[csawatsky]

BES version: 4.1.4.15
device: 8130 v 4.3.0.66 (platform 3.1.0.35)

I put in a couple of apps and configure them up with the BES, set them to deploy, required, yada yada

now, the POLC log seems to show that the apps are queue to be deployed, but they queued up about 4 hours ago. Here's what the log reads:

[40000] (04/07 09:07:41.840):{0x1768} {myemail@mydomain.com, PIN=12345678, UserId=4}SCS::PollDBQueueNewRequests - Queuing POLL_FOR_MISSING_APPS request
[40000] (04/07 09:07:42.949):{0x1754} RequestHandler::PollForMissingApps: Starting Poll For Missing Apps.
[40000] (04/07 09:07:42.949):{0x1754} SCS::RemoveAppDeliveryRequests - No App Delivery Requests purged for User id 4
[40000] (04/07 09:07:42.949):{0x1754} RequestHandler::PollForMissingApps: Failed to RemoveAppDeliveryRequests.
[40000] (04/07 09:07:43.887):{0x1754} {myemail@mydomain.com, PIN=12345678, UserId=4}RequestHandler::PollForMissingApps: Queuing the package app1, consisting of 1 modules in 1 parts.
[40000] (04/07 09:07:43.934):{0x1754} {myemail@mydomain.com, PIN=12345678, UserId=4}RequestHandler::QueueModule: Queuing part 1 of 1, module C:\mypath\app1\app1.cod of the package app1.
[40000] (04/07 09:07:43.981):{0x1754} {myemail@mydomain.com, PIN=12345678, UserId=4}RequestHandler::PollForMissingApps: Queuing the package app2, consisting of 1 modules in 1 parts.
[40000] (04/07 09:07:44.043):{0x1754} {myemail@mydomain.com, PIN=12345678, UserId=4}RequestHandler::QueueModule: Queuing part 1 of 1, module C:\mypath\app2\app2.cod of the package app2.
[40000] (04/07 09:07:44.121):{0x1754} RequestHandler::PollForMissingApps: Completed Poll For Missing Apps, elapsed time 2 seconds.
[40000] (04/07 09:07:44.137):{0x1768} {myemail@mydomain.com, PIN=12345678, UserId=4}SCS::PollDBQueueNewRequests - Queuing SEND_APC_ITPOLICY request
[40000] (04/07 09:07:44.152):{0x1768} {myemail@mydomain.com, PIN=12345678, UserId=4}SCS::PollDBQueueNewRequests - Queuing SEND_APC_ITPOLICY request
[30000] (04/07 09:07:44.871):{0x174C} {myemail@mydomain.com, PIN=12345678, UserId=4}RequestHandler::SendQueuedITAdminCommandT oDevice Sending data to device, contentType=ITADMIN, size=344, RefId=0, TransactionId=-942797171, Tag=11
[40000] (04/07 09:07:44.871):{0x174C} {myemail@mydomain.com, PIN=12345678, UserId=4}RequestHandler::SendToRelay - SubmitToRelaySendQ, Tag=11
[40000] (04/07 09:07:44.871):{0x1740} [BIPP] Send data, Tag=11
[30000] (04/07 09:07:44.887):{0x1750} {myemail@mydomain.com, PIN=12345678, UserId=4}RequestHandler::SendQueuedITAdminCommandT oDevice Sending data to device, contentType=ITADMIN, size=344, RefId=0, TransactionId=-942797170, Tag=12
[40000] (04/07 09:07:44.887):{0x1750} {myemail@mydomain.com, PIN=12345678, UserId=4}RequestHandler::SendToRelay - SubmitToRelaySendQ, Tag=12
[40000] (04/07 09:07:44.887):{0x1740} [BIPP] Send data, Tag=12


Does it usually take a long time after this point for the apps to actually make it to my phone? Is there anywhere else I can check to find the status?

thanks!

[hdawg]

The POLC log is the best place to look ... you can check your HH to see if the app installed but no icon appeared.

Try:

1) making sure device.xml on the server has the device model of the unit you're deploying to
2) make use of the deploy applications function within 4.1.4 so you don't have to wait the 4 hours to do a full deploy.

Are you able to make a successful change to IT Policy / resend service books to the user in question?

[csawatsky]

I am able to make a change to IT policy, yes it goes through no problem

The POLC log just keeps showing that the apps are queue for delivery

[40000] (04/08 02:24:16.579):{0x1668} {myemail@mydomain.com, PIN=12345678, UserId=4}RequestHandler::PollForMissingApps - Transaction Id already queued for package App1.

Is there any place that one can see what is all in queue for deployment?


THANKS!

[Ugg]

I've seen "Transaction Id already queued" appear when application sending gets "confused".

In the past I've used the SQL in this link to fix it:
BlackBerry Search Results

although now another possible cause has appeared on BTSC:
BlackBerry Search Results

To see what's in the queue, use something like SQL Server enterprise manager to look at the IT Admin queue (as per the RIM articles except "select" rather than delete" from ITAdminQueue). This should give you an idea about what's going where. You'll need to find someone else to explain all the columns though.

[csawatsky]

ok so I looked in the table itadminqueue for rows as per the first KB link. There were no rows that matched, but there were some really old (a few months) rows in there, so I just emptied the table (kept a backup, mind you)

Still no apps on the phone, but a new message in the POLC log...


[40000] (04/09 09:52:30.489):{0x1838} {myemail@mydomain.com, PIN=12345678, UserId=4}SCS::PollDBQueueNewRequests - Queuing POLL_FOR_MISSING_APPS request
[40000] (04/09 09:52:31.489):{0x1BD8} RequestHandler::PollForMissingApps: Starting Poll For Missing Apps.
[40000] (04/09 09:52:31.489):{0x1BD8} SCS::RemoveAppDeliveryRequests - No App Delivery Requests purged for User id 4
[40000] (04/09 09:52:31.489):{0x1BD8} RequestHandler::PollForMissingApps: Failed to RemoveAppDeliveryRequests.
[40000] (04/09 09:52:31.989):{0x748} [BIPP] Ping 22 sent
[40000] (04/09 09:52:31.989):{0x104C} [BIPP] PingResponse 22 received
[40000] (04/09 09:52:32.192):{0x1BD8} {myemail@mydomain.com, PIN=12345678, UserId=4}RequestHandler::PollForMissingApps: Queuing the package App1, consisting of 1 modules in 1 parts.
[40000] (04/09 09:52:32.223):{0x1BD8} {myemail@mydomain.com, PIN=12345678, UserId=4}RequestHandler::QueueModule: Queuing part 1 of 1, module c:\mypath\app1\app1.codApp1.cod of the package App1.
[40000] (04/09 09:52:32.254):{0x1BD8} {myemail@mydomain.com, PIN=12345678, UserId=4}RequestHandler::PollForMissingApps: Queuing the package App2, consisting of 1 modules in 1 parts.
[40000] (04/09 09:52:32.270):{0x1BD8} {myemail@mydomain.com, PIN=12345678, UserId=4}RequestHandler::QueueModule: Queuing part 1 of 1, module c:\mypath\app2\app2.cod_northcubed_App2_app.cod of the package App2.
[40000] (04/09 09:52:32.301):{0x1BD8} RequestHandler::PollForMissingApps: Completed Poll For Missing Apps, elapsed time 1 seconds.
[40000] (04/09 09:52:32.301):{0x1838} {myemail@mydomain.com, PIN=12345678, UserId=4}SCS::PollDBQueueNewRequests - Queuing SEND_APC_ITPOLICY request
[40000] (04/09 09:52:32.317):{0x1838} {myemail@mydomain.com, PIN=12345678, UserId=4}SCS::PollDBQueueNewRequests - Queuing SEND_APC_ITPOLICY request
[30000] (04/09 09:52:36.551):{0x1D48} {myemail@mydomain.com, PIN=12345678, UserId=4}RequestHandler::SendQueuedITAdminCommandT oDevice Sending data to device, contentType=ITADMIN, size=349, RefId=0, TransactionId=-939733778, Tag=31
[40000] (04/09 09:52:36.551):{0x1D48} {myemail@mydomain.com, PIN=12345678, UserId=4}RequestHandler::SendToRelay - SubmitToRelaySendQ, Tag=31
[40000] (04/09 09:52:36.551):{0x748} [BIPP] Send data, Tag=31
[30000] (04/09 09:52:36.551):{0xF88} {myemail@mydomain.com, PIN=12345678, UserId=4}RequestHandler::SendQueuedITAdminCommandT oDevice Sending data to device, contentType=ITADMIN, size=349, RefId=0, TransactionId=-939733778, Tag=32
[40000] (04/09 09:52:36.551):{0xF88} {myemail@mydomain.com, PIN=12345678, UserId=4}RequestHandler::SendToRelay - SubmitToRelaySendQ, Tag=32
[40000] (04/09 09:52:36.551):{0x748} [BIPP] Send data, Tag=32
[40000] (04/09 09:52:40.817):{0x104C} [BIPP] Received status DELIVERED, Tag=31
[30000] (04/09 09:52:40.817):{0x1850} {myemail@mydomain.com, PIN=12345678, UserId=4}RequestHandler::DoDeviceSentProcessing - Message has been delivered to device, Tag=31
[40000] (04/09 09:52:40.817):{0x1850} {myemail@mydomain.com, PIN=12345678, UserId=4}RequestHandler::DoITPolicyDeviceSentProce ssing - ITPolicy GME Receive Ack for the command SEND_APC_ITPOLICY - Processing packet, Tag=31
[40000] (04/09 09:52:40.832):{0x1850} {myemail@mydomain.com, PIN=12345678, UserId=4}SCS::QueueNextSequenceforGroup - Queuing SEND_APC_APP request
[40000] (04/09 09:52:40.848):{0xAA8} {myemail@mydomain.com, PIN=12345678, UserId=4}RequestHandler::GetApplicationData: Loading the module at offset 0, length 2147483647, path "c:\mypath\app1\app1.codApp1.cod".
[40000] (04/09 09:52:40.848):{0xAA8} {myemail@mydomain.com, PIN=12345678, UserId=4}RequestHandler::SendToRelay - SubmitToRelaySendQ, Tag=33
[40000] (04/09 09:52:40.848):{0xAA8} {myemail@mydomain.com, PIN=12345678, UserId=4}RequestHandler::SendApp: Sending the module c:\mypath\app1\app1.codApp1.cod for entry id 26.
[40000] (04/09 09:52:40.848):{0x748} [BIPP] Send data, Tag=33
[40000] (04/09 09:52:40.926):{0x104C} [BIPP] Received status DELIVERED, Tag=32
[30000] (04/09 09:52:40.926):{0xF88} {myemail@mydomain.com, PIN=12345678, UserId=4}RequestHandler::DoDeviceSentProcessing - Message has been delivered to device, Tag=32
[40000] (04/09 09:52:40.926):{0xF88} {myemail@mydomain.com, PIN=12345678, UserId=4}RequestHandler::DoITPolicyDeviceSentProce ssing - ITPolicy GME Receive Ack for the command SEND_APC_ITPOLICY - Processing packet, Tag=32
[40000] (04/09 09:52:40.942):{0xF88} {myemail@mydomain.com, PIN=12345678, UserId=4}SCS::QueueNextSequenceforGroup - Queuing SEND_APC_APP request
[40304] (04/09 09:52:40.942):{0x1850} WorkerThreadPool:: ThreadProc(): Thread released with empty queue
[40000] (04/09 09:52:40.942):{0x1D48} {myemail@mydomain.com, PIN=12345678, UserId=4}RequestHandler::GetApplicationData: Loading the module at offset 0, length 2147483647, path "c:\mypath\app2\app2.cod_northcubed_App2_app.c od".
[40000] (04/09 09:52:40.957):{0x1D48} {myemail@mydomain.com, PIN=12345678, UserId=4}RequestHandler::SendToRelay - SubmitToRelaySendQ, Tag=34
[40000] (04/09 09:52:40.957):{0x1D48} {myemail@mydomain.com, PIN=12345678, UserId=4}RequestHandler::SendApp: Sending the module c:\mypath\app2\app2.cod_northcubed_App2_app.cod for entry id 28.
[40000] (04/09 09:52:40.957):{0x748} [BIPP] Send data, Tag=34
[40000] (04/09 09:52:44.207):{0x104C} [BIPP] Received status DELIVERED, Tag=33
[30000] (04/09 09:52:44.207):{0x1BD8} {myemail@mydomain.com, PIN=12345678, UserId=4}RequestHandler::DoDeviceSentProcessing - Message has been delivered to device, Tag=33
[40000] (04/09 09:52:44.207):{0x1BD8} {myemail@mydomain.com, PIN=12345678, UserId=4}RequestHandler::DoITPolicyDeviceSentProce ssing - ITPolicy GME Receive Ack for the command SEND_APC_APP - Processing packet, Tag=33
[40000] (04/09 09:52:44.598):{0x104C} [BIPP] Received status DELIVERED, Tag=34
[30000] (04/09 09:52:44.598):{0xAA8} {myemail@mydomain.com, PIN=12345678, UserId=4}RequestHandler::DoDeviceSentProcessing - Message has been delivered to device, Tag=34
[40000] (04/09 09:52:44.598):{0xAA8} {myemail@mydomain.com, PIN=12345678, UserId=4}RequestHandler::DoITPolicyDeviceSentProce ssing - ITPolicy GME Receive Ack for the command SEND_APC_APP - Processing packet, Tag=34
[40000] (04/09 09:52:48.129):{0x104C} [BIPP] Received datagram, Tag=15096319
[40000] (04/09 09:52:48.129):{0xF88} {myemail@mydomain.com, PIN=12345678, UserId=4}RequestHandler::DoGMEReceiveProcessing - Receiving packet from device, size=46, TransactionId=465815277, Tag=15096319, content type=ITADMIN, cmd=0x3
[20000] (04/09 09:52:48.129):{0xF88} {myemail@mydomain.com, PIN=12345678, UserId=4}RequestHandler::HandleITADMINDataCommand - Unable to find matching entry id for PIN=12345678 and ITCommand=SET_IT_POLICY_COMMAND
[40000] (04/09 09:52:48.129):{0xF88} {myemail@mydomain.com, PIN=12345678, UserId=4}RequestHandler::SendToRelay - SubmitToRelaySendQ, Tag=15096319
[40000] (04/09 09:52:48.129):{0x748} [BIPP] Send status DATA_ACCEPTED, Tag=15096319
[40000] (04/09 09:52:55.144):{0x104C} [BIPP] Received datagram, Tag=15096321
[40000] (04/09 09:52:55.144):{0x1850} {myemail@mydomain.com, PIN=12345678, UserId=4}RequestHandler::DoGMEReceiveProcessing - Receiving packet from device, size=46, TransactionId=465815279, Tag=15096321, content type=ITADMIN, cmd=0x3
[20000] (04/09 09:52:55.144):{0x1850} {myemail@mydomain.com, PIN=12345678, UserId=4}RequestHandler::HandleITADMINDataCommand - Unable to find matching entry id for PIN=12345678 and ITCommand=SET_IT_POLICY_COMMAND
[40000] (04/09 09:52:55.144):{0x1850} {myemail@mydomain.com, PIN=12345678, UserId=4}RequestHandler::SendToRelay - SubmitToRelaySendQ, Tag=15096321
[40000] (04/09 09:52:55.144):{0x748} [BIPP] Send status DATA_ACCEPTED, Tag=15096321
[40000] (04/09 09:53:55.158):{0x748} [BIPP] Ping 23 sent




so yeah, anyone else have any ideas? I'm at a loss!

[mahoward]

In the first set of logs, it was hanging on trying to send your device the application IT Policy, so it never got to send the app. You see, when you have an application control policy assigned to an app, then it must send the policy before the app.

In the second set of logs above, it appears that the app policy sending issue is resolved, but it is getting a weird response back from the device after the policy is accepted but before the app is sent.

Looks like a weird policy issue?

First I would remove the application control policy from the app and just try to send the app and see if that works.

[csawatsky]

Originally Posted by mahoward

First I would remove the application control policy from the app and just try to send the app and see if that works.

I now tried deleting the application control policy, AND the software config

recreated a software config with a different name, no policy. hit deploy button

showed up in logs as pushing the app out, looked positive. checked logs later, still saying that the stuff is already queued.

I guess I'm going to try randomly deleting rows from the itadminqueue table to see if something is jamming up the queue maybe?

Any other ideas? complete BPS reinstall? I only have two phones in it at this point, so that's a feasible option