Plugin (mostly) not working for us

Support and questions for using and managing Chocolatey NuGet inside of Labtech
Post Reply
HenningIdrift
Posts: 4
Joined: Mon Apr 08, 2019 7:20 pm
4

Plugin (mostly) not working for us

Post by HenningIdrift »

We only have part of the plugin working. And not the good parts.
Please help/advice us on how to proceed.
We are using version 3.0.0.16 of the chocolatey for automate plugin
We have (a few times) tried dropping all tables and restarting the Database agent to have the tables recreated.
Our CW Automate solution is running onpremise.

In the Chocolatey for automate license info (clicking the rocket) it says valid until june 22, 2019 and Agents Licensed: 1 .

When restarting the Database agent the following error is logged in Plugin_ChocolateyForAutomate_Errors:
LTAgent v190.138 - 5/16/2019 6:33:13 PM - Plugin Error ChocolateyForAutomate, Version=3.0.0.16, Culture=neutral, PublicKeyToken=null: SetSQLColumn count doesn't match value count at row 2:::

Observations so far, these WORK:
It seems to deploy the chocolatey toolkit ok to all computers after enabling a location
We can run a version scan from the location view of an applcation, and the scripts are run on each agent and a chocolatey inventory is updated with number of apps etc. correctly (all applications) (GetVersions command in SQL table)

PUSH ALL WORKSTATIONS
Attempt to push install a applcation to all workstations results in the following message in Plugin_ChocolateyForAutomate.txt log on the labtech server:
Command Manager has [1] pending commands:::
LTAgent v190.138 - 5/16/2019 3:24:32 PM - Plugin ChocolateyForAutomate, Version=3.0.0.16, Culture=neutral, PublicKeyToken=null: Failed execution of commands - Index (zero based) must be greater than or equal to zero and less than the size of the argument list.:::
LTAgent v190.138 - 5/16/2019 3:24:32 PM - Plugin ChocolateyForAutomate, Version=3.0.0.16, Culture=neutral, PublicKeyToken=null: Chocolatey_Command_Manager completed.:::

And no command or scripts can be seen attempted to run on the agent.
Observing the SQL I can see an insert into plugin_p4l_chocolatey_commands with InstallAllWorkstations command beeing done, with the correct clientid and issuedate, and I can see the executedate beeing updated when running, but nothing happening on the agent/endpoint.

PUSH SINGLE WORKSTATION
Running an install on a single workstation has simular symptoms to all workstation, command logged in SQL is Install
We get the same error in Plugin_ChocolateyForAutomate.txt "Index (zero based) must be greater than..."
However we CAN see a command (not a script) beeing run on the single workstation, and this actually seem to install the application correctly.
For the application I am testing with (7zip.install) it logs the following execute command in labtech:
"cmd!!! /C C:\programdata\Chocolatey\choco.exe install 7zip.install -y"
We have tried both with the application installed and uninstalled and it installs if not installed and gives an error that already installed if it's already installed.
While it does install the application, it DOES not update the SQL plugin_p4l_chocolatey_commands table with executedate, it simply stays (NULL) and thus this command is repeatedly attempted every 10 minute cycle until
we manually delete the row from SQL or insert an executedate manually in the table.

UPDATE SINGLE WORKSTATION and UPDATE ALL WORKSTATIONS
Seems to work ok from Plugin_ChocolateyForAutomate.txt , we can see there is [1] pending commands and the SQL plugin_p4l_chocolatey_commands get updated with executedate,
command (in table) is UpdateC for single workstation and UpdateClient for all.
On UPDATE ALL we get a line per workstation in Plugin_ChocolateyForAutomate.txt:
Exectuing commands on agent ID 5879 Command = UpdateClient App = 7zip.install:::

However nothing happens on any of the workstations, no command or script can be observed running to trigger chocolate and actually do any work.

REMOVE SINGLE WORKSTATION.
Remove command is logged in SQL plugin_p4l_chocolatey_commands but upon execution it DOES not update the SQL plugin_p4l_chocolatey_commands table with executedate.
Since the executedata is not updated, this command is reattempted each 10 minute cycle.
Plugin_ChocolateyForAutomate.txt displays the following error:
LTAgent v190.138 - 5/16/2019 6:26:59 PM - Plugin ChocolateyForAutomate, Version=3.0.0.16, Culture=neutral, PublicKeyToken=null: Failed execution of commands - Index (zero based) must be greater than or equal to zero and less than the size of the argument list.:::
It does run a command (no script) doing an "cmd!!! /C C:\programdata\Chocolatey\choco.exe uninstall 7zip.install -y" and this seems to work correctly.

REMOVE ALL WORKSTATIONS (UNTESTED)
This is not tested, we don't want to play with that before the others are working.

User avatar
Cubert
Posts: 2430
Joined: Tue Dec 29, 2015 7:57 pm
8
Contact:

Re: Plugin (mostly) not working for us

Post by Cubert »

HenningIdrift wrote: Thu May 16, 2019 4:43 pm We only have part of the plugin working. And not the good parts.
Please help/advice us on how to proceed.
We are using version 3.0.0.16 of the chocolatey for automate plugin
We have (a few times) tried dropping all tables and restarting the Database agent to have the tables recreated.
Our CW Automate solution is running onpremise.

In the Chocolatey for automate license info (clicking the rocket) it says valid until june 22, 2019 and Agents Licensed: 1 .
This would be accurate. We allow unlimited agents so license shows (1)


When restarting the Database agent the following error is logged in Plugin_ChocolateyForAutomate_Errors:
LTAgent v190.138 - 5/16/2019 6:33:13 PM - Plugin Error ChocolateyForAutomate, Version=3.0.0.16, Culture=neutral, PublicKeyToken=null: SetSQLColumn count doesn't match value count at row 2:::

I will look into this error

Observations so far, these WORK:
It seems to deploy the chocolatey toolkit ok to all computers after enabling a location
We can run a version scan from the location view of an applcation, and the scripts are run on each agent and a chocolatey inventory is updated with number of apps etc. correctly (all applications) (GetVersions command in SQL table)



PUSH ALL WORKSTATIONS
Attempt to push install a applcation to all workstations results in the following message in Plugin_ChocolateyForAutomate.txt log on the labtech server:
Command Manager has [1] pending commands:::
LTAgent v190.138 - 5/16/2019 3:24:32 PM - Plugin ChocolateyForAutomate, Version=3.0.0.16, Culture=neutral, PublicKeyToken=null: Failed execution of commands - Index (zero based) must be greater than or equal to zero and less than the size of the argument list.:::
LTAgent v190.138 - 5/16/2019 3:24:32 PM - Plugin ChocolateyForAutomate, Version=3.0.0.16, Culture=neutral, PublicKeyToken=null: Chocolatey_Command_Manager completed.:::

Ok lets look at this issue, We are hitting the "install all agents" function correctly but do not execute any cmds on agents and error that we did not have any data returned from our who in client is able to install query. So lets start with the query and see what we get.

The query below is for client ID 1 so you might need to modify the client ID at the end of the query to repersent the client your working on.

Code: Select all

SELECT a.ComputerID, a.Active, a.Suspend, IF(c.LastContact > date_add(now(),interval -5 minute),'Yes','No') As Online, c.Name as Computer, (SELECT count(*) FROM plugin_p4l_chocolatey_computers WHERE Application = 'Chocolatey' AND AppInstalled = '1' AND ComputerID = a.ComputerID) As Framework, (SELECT COUNT(*) FROM commands WHERE Status < 3 and ComputerID = a.ComputerID) As RunningCMDs, (SELECT count(*) FROM plugin_p4l_chocolatey_computers WHERE  Application NOT LIKE 'Chocolatey' AND AppInstalled = '0' AND ComputerID = a.ComputerID) As RUNINSTALLER FROM plugin_p4l_chocolatey_computer_enable a Left Join computers c on a.ComputerID = c.ComputerID WHERE a.ComputerID IN (Select computerID from computers WHERE ClientID IN (SELECT ClientId FROM plugin_p4l_chocolatey_client_enable Where Active = '1') AND OS LIKE '%Microsoft%') AND a.Active = '1' and a.Suspend = '0' AND c.OS NOT LIKE '%Server%' AND c.ClientID ='1' GROUP BY a.computerID
This should return a table full of data about clientID 1
Capture.PNG
Capture.PNG (10.45 KiB) Viewed 23335 times
Well, crap LOL! As I sit here walking through the function to explain how its working to you I found a big typo in code that would cause exactly what you see here with any install our uninstall commands that are client wide. So at the end of this post we will release the updated version resolving issues we find today. Thay you for posting with enough detail to allow us to revisit easily.






And no command or scripts can be seen attempted to run on the agent.
Observing the SQL I can see an insert into plugin_p4l_chocolatey_commands with InstallAllWorkstations command beeing done, with the correct clientid and issuedate, and I can see the executedate beeing updated when running, but nothing happening on the agent/endpoint.

This would be consistent with the found issues.

PUSH SINGLE WORKSTATION
Running an install on a single workstation has simular symptoms to all workstation, command logged in SQL is Install
We get the same error in Plugin_ChocolateyForAutomate.txt "Index (zero based) must be greater than..."
However we CAN see a command (not a script) beeing run on the single workstation, and this actually seem to install the application correctly.
We could use more info here, Are we seeing a log during install like so?
Command Manager has XXX pending commands Followed by Exectuing commands on agent ID before and or after the SQL error. Trying to make sure that above error was not a result of our newly found typo as the install agent is much different then install client function and typo there does not effect this function. (Suggest we update with fix and retest to see if this is just how logs were placed in txt file.


For the application I am testing with (7zip.install) it logs the following execute command in labtech:
"cmd!!! /C C:\programdata\Chocolatey\choco.exe install 7zip.install -y"
We have tried both with the application installed and uninstalled and it installs if not installed and gives an error that already installed if it's already installed.
While it does install the application, it DOES not update the SQL plugin_p4l_chocolatey_commands table with executedate, it simply stays (NULL) and thus this command is repeatedly attempted every 10 minute cycle until
we manually delete the row from SQL or insert an executedate manually in the table.

And you see no SQL errors in main LThost error logs?

Code: Select all

UPDATE IGNORE plugin_p4l_chocolatey_computers SET InstallDate = NOW(), AppInstalled = '1', Attempts = (Attempts + 1) WHERE ComputerID = '{0}' and Application = '{2}' 
AH crap!! have to LOL again! There in our SQL code lies the issue! Variables (0) and (2)? Where did (1) go, just decided not to use consistent numbers? This is our bad... That (2) should be a (1).

This fix will also be in the build below.





UPDATE SINGLE WORKSTATION and UPDATE ALL WORKSTATIONS
Seems to work ok from Plugin_ChocolateyForAutomate.txt , we can see there is [1] pending commands and the SQL plugin_p4l_chocolatey_commands get updated with executedate,
command (in table) is UpdateC for single workstation and UpdateClient for all.
On UPDATE ALL we get a line per workstation in Plugin_ChocolateyForAutomate.txt:
Exectuing commands on agent ID 5879 Command = UpdateClient App = 7zip.install:::

However nothing happens on any of the workstations, no command or script can be observed running to trigger chocolate and actually do any work.

This has part of 1st issue with typo and should be fixed below

REMOVE SINGLE WORKSTATION.
Remove command is logged in SQL plugin_p4l_chocolatey_commands but upon execution it DOES not update the SQL plugin_p4l_chocolatey_commands table with executedate.
Since the executedata is not updated, this command is reattempted each 10 minute cycle.
Plugin_ChocolateyForAutomate.txt displays the following error:
LTAgent v190.138 - 5/16/2019 6:26:59 PM - Plugin ChocolateyForAutomate, Version=3.0.0.16, Culture=neutral, PublicKeyToken=null: Failed execution of commands - Index (zero based) must be greater than or equal to zero and less than the size of the argument list.:::
It does run a command (no script) doing an "cmd!!! /C C:\programdata\Chocolatey\choco.exe uninstall 7zip.install -y" and this seems to work correctly.

This was part of issue #2

REMOVE ALL WORKSTATIONS (UNTESTED)
This is not tested, we don't want to play with that before the others are working.
Would of had issue # 1
So looks like we had 2 issues that needed fixed

#1 was a typo, actually a reference to incorrect variable that caused the test to see if agent was ready to install to fail and no command to be run on agent. We have corrected this by updating all references to that variable. This affected any place where group installs, uninstalls or updates took place.

#2 Was a reference to a string variable out of context. which caused SQL update query to fail to update that commands were executed. This affected installs, updates and removals on single agent commands.

Here is the updated release for Chocolate For Automate.
https://delivery.shopifyapps.com/-/222b ... 0d335ea12e

We are still looking for the other SQL error reported so stay tuned.




HenningIdrift
Posts: 4
Joined: Mon Apr 08, 2019 7:20 pm
4

Re: Plugin (mostly) not working for us

Post by HenningIdrift »

Thanks for looking into the issues and releasing updates!

I will get my automate guy to update the plugin, and we will drop tables and try again soon (hopefully during this week).

I'll try to give word back if anything is still not working as expected, and if the error from Plugin_ChocolateyForAutomate_Errors.txt is still logged after update and table resets.

User avatar
Cubert
Posts: 2430
Joined: Tue Dec 29, 2015 7:57 pm
8
Contact:

Re: Plugin (mostly) not working for us

Post by Cubert »

Tables should be fine, an update of the plugin and relaunch of the DBagent will get plugin and server updated. Then relaunch the LTconsoles to get fresh update to Tech systems.

Above we gave you a pretty cool query. This query looks at all enabled agents to see if they are "ready to" do a function like install, update or remove. So when troubleshooting an agent thats does not seem to take instructions use this query to verify the "state" of the agent.

Is it seen as online?
Is it seen as having choco installed?
Is it already running more than 2 commands?
Is it active or suspended?

These all have an effect on whether or not an agent (installs, updates or removes) software.

Enjoy!

HenningIdrift
Posts: 4
Joined: Mon Apr 08, 2019 7:20 pm
4

Re: Plugin (mostly) not working for us

Post by HenningIdrift »

Thank you for the info so far.

Been doing a few more test, and first thing first:
Install on a single computer is now working perfectly, excutedate is updated and it install one time only.

Unfortunatly we are having less results with:
Update single computer
Install all computers
Update single computer

For the three not working, we however do see that ExecuteDate is updated in the SQL now, but still no commands/scripts or logs of that can be seen running on the client.

I've pasted the results from the query you provided with clientid adjusts to 2 here so we can verify that they seem ok, we get a much larger table but I've just included a few relevant computers that I'm using for testing:
"ComputerID" "Active" "Suspend" "Online" "Computer" "Framework" "RunningCMDs" "RUNINSTALLER"
"5201" "1" "0" "Yes" "LAP-TERJEW10" "1" "0" "0"
"5736" "1" "0" "Yes" "IDRIFT-LAP-OLE" "1" "0" "0"
"5791" "1" "0" "Yes" "IDRIFT-WX-OLE" "1" "0" "0"
"5835" "1" "0" "Yes" "ID-LT-81048W5" "1" "0" "0"



As far as I can see they seem to be active and found in your query, not supsended and with framework installed.


My plugin_p4l_chocolatey_commands looks like this after som testing yesterday:
"ID" "ClientID" "ComputerID" "Application" "Command" "IssueDate" "ExecuteDate" "Results" "Errors" "RetryCount" "Options"
"1" "2" "5835" "7zip.install" "Install" "2019-05-21 09:00:36" "2019-05-21 09:03:49" \N \N "0" ""
"2" "2" "0" "7zip.install" "UpdateClient" "2019-05-21 09:09:25" "2019-05-21 09:13:36" \N \N "0" ""
"3" "2" "0" "7zip.install" "GetVersions" "2019-05-21 09:20:52" "2019-05-21 09:23:26" \N \N "0" ""
"4" "2" "0" "7zip.install" "UpdateClient" "2019-05-21 10:18:00" "2019-05-21 10:23:12" \N \N "0" ""
"5" "2" "0" "7zip.install" "InstallAllWorkstations" "2019-05-21 10:28:37" "2019-05-21 10:33:02" \N \N "0" ""
"6" "2" "0" "7zip.install" "UpdateClient" "2019-05-21 10:37:59" "2019-05-21 10:42:49" \N \N "0" ""
"7" "2" "5201" "7zip.install" "UpdateC" "2019-05-21 10:53:56" "2019-05-21 11:02:52" \N \N "0" ""
"8" "2" "5201" "7zip.install" "Install" "2019-05-21 11:14:26" "2019-05-21 11:22:26" \N \N "0" ""
"9" "2" "5835" "7zip.install" "Install" "2019-05-21 11:22:46" "2019-05-21 11:32:37" \N \N "0" ""
"10" "2" "5835" "Wget" "UpdateC" "2019-05-21 11:24:16" "2019-05-21 11:32:37" \N \N "0" ""
"11" "2" "0" "7zip.install" "GetVersions" "2019-05-21 11:45:40" "2019-05-21 11:52:10" \N \N "0" ""
"12" "2" "5835" "7zip.install" "UpdateC" "2019-05-21 11:56:14" "2019-05-21 12:01:58" \N \N "0" ""


I only have a single application, 7zip.install included.
I have been done something outside of the plugin as well, like trying to install an old versjon of 7zip.install (through chocolatey) on the 5835 computer and running getversions to see if that will make an update work next try, but as far as I can see none of these commands (UpdateC/UpdateClient/InstallAllworkstations) are actually doing anything on the two clients I'm examining. I've also tried removing the software outside of the plugin and installing it again inside the plugin.

I'm verifying this by going into "commands" and "data tiles" within the GUI in automate, and I can see commands beeing run when doing an "Install" single client, as expected, and I see a script beeing queued, resulting in a series of commands beeing run for "GetVersions". I also see traces off the framework install on these computers, but it's completly blank when trying UpdateC/InstallAllWorkstations/UpdateClient


If I do a manual query to get all applications installed with computerid 5835 and 5201 (the ones im mainly testing on) and filtering on 7zip.install and chocolatey (we have a large list if not since we use the chocolatey framework a lot outside of the plugin also):
SELECT * FROM `plugin_p4l_chocolatey_computers` WHERE (computerid=5201 OR computerid=5835) AND (application LIKE 'chocolatey' OR application LIKE '7zip.install')
"ClientID" "ComputerID" "Application" "Installs" "Updates" "AppInstalled" "InstallDate" "UninstallDate" "Attempts" "InstalledVersion"
"0" "5201" "7zip.install" "True" "True" "1" "2019-05-21 11:22:26" \N "1" \N
"0" "5835" "7zip.install" "True" "True" "1" "2019-05-21 11:32:37" \N "2" \N
"2" "5201" "7zip.install" "True" "False" "1" \N \N "0" "19.0"
"2" "5201" "chocolatey" "True" "False" "1" \N \N "0" "0.10.13"
"2" "5835" "7zip.install" "True" "False" "1" "2019-05-21 11:32:37" \N "1" "18.6"
"2" "5835" "chocolatey" "True" "False" "1" \N \N "0" "0.10.13"


It does seem to find the software and the correct versions etc.
I'm a bit confused if the two top rows with clientid=0 is by design or not, they seem strange to me, this does result in double entries of the appliaction, both with clientid 0 and 2 but as I said not sure if thats significant.

I have tried to do a "reasonable amount of logs here" by extracing clientid=5835 (this is my machine) from ChocolateyForAutomate.txt from the server and the "system info", there are lots of simular lines from other clients in the log but to keep it reasonable:
LTAgent v190.138 - 5/21/2019 9:03:49 AM - Plugin ChocolateyForAutomate, Version=3.0.0.20, Culture=neutral, PublicKeyToken=null: Chocolatey_Command_Manager thread starting:::
LTAgent v190.138 - 5/21/2019 9:03:49 AM - Plugin ChocolateyForAutomate, Version=3.0.0.20, Culture=neutral, PublicKeyToken=null: Chocolatey_Command_Manager starting.:::
LTAgent v190.138 - 5/21/2019 9:03:49 AM - Plugin ChocolateyForAutomate, Version=3.0.0.20, Culture=neutral, PublicKeyToken=null: Command Manager has [1] pending commands:::
LTAgent v190.138 - 5/21/2019 9:03:49 AM - Plugin ChocolateyForAutomate, Version=3.0.0.20, Culture=neutral, PublicKeyToken=null: Exectuing commands on agent ID 5835 Command = Install App = 7zip.install:::
LTAgent v190.138 - 5/21/2019 9:03:49 AM - Plugin ChocolateyForAutomate, Version=3.0.0.20, Culture=neutral,
PublicKeyToken=null: Chocolatey_Command_Manager completed.:::
LTAgent v190.138 - 5/21/2019 9:13:36 AM - Plugin ChocolateyForAutomate, Version=3.0.0.20, Culture=neutral, PublicKeyToken=null: Chocolatey_Command_Manager thread starting:::
LTAgent v190.138 - 5/21/2019 9:13:36 AM - Plugin ChocolateyForAutomate, Version=3.0.0.20, Culture=neutral, PublicKeyToken=null: Chocolatey_Command_Manager starting.:::
LTAgent v190.138 - 5/21/2019 9:13:36 AM - Plugin ChocolateyForAutomate, Version=3.0.0.20, Culture=neutral, PublicKeyToken=null: Command Manager has [1] pending commands:::
LTAgent v190.138 - 5/21/2019 9:13:36 AM - Plugin ChocolateyForAutomate, Version=3.0.0.20, Culture=neutral, PublicKeyToken=null: Exectuing commands on agent ID 5835 Command = UpdateClient App = 7zip.install:::
PublicKeyToken=null: Chocolatey_Command_Manager thread starting:::
LTAgent v190.138 - 5/21/2019 10:23:12 AM - Plugin ChocolateyForAutomate, Version=3.0.0.20, Culture=neutral, PublicKeyToken=null: Chocolatey_Command_Manager starting.:::
LTAgent v190.138 - 5/21/2019 10:23:12 AM - Plugin ChocolateyForAutomate, Version=3.0.0.20, Culture=neutral, PublicKeyToken=null: Command Manager has [1] pending commands:::
LTAgent v190.138 - 5/21/2019 10:23:12 AM - Plugin ChocolateyForAutomate, Version=3.0.0.20, Culture=neutral,
LTAgent v190.138 - 5/21/2019 10:23:12 AM - Plugin ChocolateyForAutomate, Version=3.0.0.20, Culture=neutral, PublicKeyToken=null: Exectuing commands on agent ID 5835 Command = UpdateClient App = 7zip.install:::
LTAgent v190.138 - 5/21/2019 10:23:12 AM - Plugin ChocolateyForAutomate, Version=3.0.0.20, Culture=neutral, PublicKeyToken=null: Chocolatey_Command_Manager completed.:::

I'll stop there, this sequence seem to repeat itself for the other commands, both working and not working, but we can provide more if needed to troubleshoot.

In Plugin_ChocolateyForAutomate_Errors we still have the SQL error mentioned earlier but I know you are still checking that out, just for completness sake:
LTAgent v190.138 - 5/21/2019 8:09:46 AM - Plugin Error ChocolateyForAutomate, Version=3.0.0.20, Culture=neutral, PublicKeyToken=null: SetSQLColumn count doesn't match value count at row 2:::

Our server LTSQLErrors.txt has some errors regarding missing tables, but this makes sense of course since we dropped them to have them recreated (we find this reduced bloat when testing):
LTAgent v190.138 - 5/21/2019 8:10:06 AM - ESQL Table 'labtech.plugin_p4l_chocolatey_installed_apps' doesn't exist <REDACTED>:::

We also have some errors related to another plugin, that lists an invalid query involving computer names, operating system and product-keys but this does not match the timestamps or schedule of this plugin and I'm almost certain they cant be related.


Do you need any more info from us or need us to complete a sequence of actions in any specific order to help reproduce or shed light on the problems/issues?

User avatar
Cubert
Posts: 2430
Joined: Tue Dec 29, 2015 7:57 pm
8
Contact:

Re: Plugin (mostly) not working for us

Post by Cubert »

HenningIdrift wrote: Wed May 22, 2019 9:10 am Thank you for the info so far.

Been doing a few more test, and first thing first:
Install on a single computer is now working perfectly, excutedate is updated and it install one time only.

Unfortunatly we are having less results with:
Update single computer
Install all computers
Update single computer

For the three not working, we however do see that ExecuteDate is updated in the SQL now, but still no commands/scripts or logs of that can be seen running on the client.



Hmmm... In the logs did we ever see during same time frame any logs that showed "Exectuing commands on agent ID "? Should of seen it during the install, update and remove
If we do note see that then we must of failed the test to see if (#1 Are we online and #2 do we have excessive cmds running <2). Either test fails and the command is skipped.

I've pasted the results from the query you provided with clientid adjusts to 2 here so we can verify that they seem ok, we get a much larger table but I've just included a few relevant computers that I'm using for testing:
"ComputerID" "Active" "Suspend" "Online" "Computer" "Framework" "RunningCMDs" "RUNINSTALLER"
"5201" "1" "0" "Yes" "LAP-TERJEW10" "1" "0" "0"
"5736" "1" "0" "Yes" "IDRIFT-LAP-OLE" "1" "0" "0"
"5791" "1" "0" "Yes" "IDRIFT-WX-OLE" "1" "0" "0"
"5835" "1" "0" "Yes" "ID-LT-81048W5" "1" "0" "0"

looks like cmds = 1 so thats good

As far as I can see they seem to be active and found in your query, not supsended and with framework installed.


My plugin_p4l_chocolatey_commands looks like this after som testing yesterday:
"ID" "ClientID" "ComputerID" "Application" "Command" "IssueDate" "ExecuteDate" "Results" "Errors" "RetryCount" "Options"
"1" "2" "5835" "7zip.install" "Install" "2019-05-21 09:00:36" "2019-05-21 09:03:49" \N \N "0" ""
"2" "2" "0" "7zip.install" "UpdateClient" "2019-05-21 09:09:25" "2019-05-21 09:13:36" \N \N "0" ""
"3" "2" "0" "7zip.install" "GetVersions" "2019-05-21 09:20:52" "2019-05-21 09:23:26" \N \N "0" ""
"4" "2" "0" "7zip.install" "UpdateClient" "2019-05-21 10:18:00" "2019-05-21 10:23:12" \N \N "0" ""
"5" "2" "0" "7zip.install" "InstallAllWorkstations" "2019-05-21 10:28:37" "2019-05-21 10:33:02" \N \N "0" ""
"6" "2" "0" "7zip.install" "UpdateClient" "2019-05-21 10:37:59" "2019-05-21 10:42:49" \N \N "0" ""
"7" "2" "5201" "7zip.install" "UpdateC" "2019-05-21 10:53:56" "2019-05-21 11:02:52" \N \N "0" ""
"8" "2" "5201" "7zip.install" "Install" "2019-05-21 11:14:26" "2019-05-21 11:22:26" \N \N "0" ""
"9" "2" "5835" "7zip.install" "Install" "2019-05-21 11:22:46" "2019-05-21 11:32:37" \N \N "0" ""
"10" "2" "5835" "Wget" "UpdateC" "2019-05-21 11:24:16" "2019-05-21 11:32:37" \N \N "0" ""
"11" "2" "0" "7zip.install" "GetVersions" "2019-05-21 11:45:40" "2019-05-21 11:52:10" \N \N "0" ""
"12" "2" "5835" "7zip.install" "UpdateC" "2019-05-21 11:56:14" "2019-05-21 12:01:58" \N \N "0" ""

I see the issue here in cmds.. your update command has a "C" in it. that's not valid... Ok i will have a new version release below resolving this.


Let me stop here and fix the current issue and I will add some logging into the command executor to get more details on where in the functions it bails out.

I will post an update below today at some point.



I only have a single application, 7zip.install included.
I have been done something outside of the plugin as well, like trying to install an old versjon of 7zip.install (through chocolatey) on the 5835 computer and running getversions to see if that will make an update work next try, but as far as I can see none of these commands (UpdateC/UpdateClient/InstallAllworkstations) are actually doing anything on the two clients I'm examining. I've also tried removing the software outside of the plugin and installing it again inside the plugin.

I'm verifying this by going into "commands" and "data tiles" within the GUI in automate, and I can see commands beeing run when doing an "Install" single client, as expected, and I see a script beeing queued, resulting in a series of commands beeing run for "GetVersions". I also see traces off the framework install on these computers, but it's completly blank when trying UpdateC/InstallAllWorkstations/UpdateClient


If I do a manual query to get all applications installed with computerid 5835 and 5201 (the ones im mainly testing on) and filtering on 7zip.install and chocolatey (we have a large list if not since we use the chocolatey framework a lot outside of the plugin also):
SELECT * FROM `plugin_p4l_chocolatey_computers` WHERE (computerid=5201 OR computerid=5835) AND (application LIKE 'chocolatey' OR application LIKE '7zip.install')
"ClientID" "ComputerID" "Application" "Installs" "Updates" "AppInstalled" "InstallDate" "UninstallDate" "Attempts" "InstalledVersion"
"0" "5201" "7zip.install" "True" "True" "1" "2019-05-21 11:22:26" \N "1" \N
"0" "5835" "7zip.install" "True" "True" "1" "2019-05-21 11:32:37" \N "2" \N
"2" "5201" "7zip.install" "True" "False" "1" \N \N "0" "19.0"
"2" "5201" "chocolatey" "True" "False" "1" \N \N "0" "0.10.13"
"2" "5835" "7zip.install" "True" "False" "1" "2019-05-21 11:32:37" \N "1" "18.6"
"2" "5835" "chocolatey" "True" "False" "1" \N \N "0" "0.10.13"


It does seem to find the software and the correct versions etc.
I'm a bit confused if the two top rows with clientid=0 is by design or not, they seem strange to me, this does result in double entries of the appliaction, both with clientid 0 and 2 but as I said not sure if thats significant.

I have tried to do a "reasonable amount of logs here" by extracing clientid=5835 (this is my machine) from ChocolateyForAutomate.txt from the server and the "system info", there are lots of simular lines from other clients in the log but to keep it reasonable:
LTAgent v190.138 - 5/21/2019 9:03:49 AM - Plugin ChocolateyForAutomate, Version=3.0.0.20, Culture=neutral, PublicKeyToken=null: Chocolatey_Command_Manager thread starting:::
LTAgent v190.138 - 5/21/2019 9:03:49 AM - Plugin ChocolateyForAutomate, Version=3.0.0.20, Culture=neutral, PublicKeyToken=null: Chocolatey_Command_Manager starting.:::
LTAgent v190.138 - 5/21/2019 9:03:49 AM - Plugin ChocolateyForAutomate, Version=3.0.0.20, Culture=neutral, PublicKeyToken=null: Command Manager has [1] pending commands:::
LTAgent v190.138 - 5/21/2019 9:03:49 AM - Plugin ChocolateyForAutomate, Version=3.0.0.20, Culture=neutral, PublicKeyToken=null: Exectuing commands on agent ID 5835 Command = Install App = 7zip.install:::
LTAgent v190.138 - 5/21/2019 9:03:49 AM - Plugin ChocolateyForAutomate, Version=3.0.0.20, Culture=neutral,
PublicKeyToken=null: Chocolatey_Command_Manager completed.:::
LTAgent v190.138 - 5/21/2019 9:13:36 AM - Plugin ChocolateyForAutomate, Version=3.0.0.20, Culture=neutral, PublicKeyToken=null: Chocolatey_Command_Manager thread starting:::
LTAgent v190.138 - 5/21/2019 9:13:36 AM - Plugin ChocolateyForAutomate, Version=3.0.0.20, Culture=neutral, PublicKeyToken=null: Chocolatey_Command_Manager starting.:::
LTAgent v190.138 - 5/21/2019 9:13:36 AM - Plugin ChocolateyForAutomate, Version=3.0.0.20, Culture=neutral, PublicKeyToken=null: Command Manager has [1] pending commands:::
LTAgent v190.138 - 5/21/2019 9:13:36 AM - Plugin ChocolateyForAutomate, Version=3.0.0.20, Culture=neutral, PublicKeyToken=null: Exectuing commands on agent ID 5835 Command = UpdateClient App = 7zip.install:::
PublicKeyToken=null: Chocolatey_Command_Manager thread starting:::
LTAgent v190.138 - 5/21/2019 10:23:12 AM - Plugin ChocolateyForAutomate, Version=3.0.0.20, Culture=neutral, PublicKeyToken=null: Chocolatey_Command_Manager starting.:::
LTAgent v190.138 - 5/21/2019 10:23:12 AM - Plugin ChocolateyForAutomate, Version=3.0.0.20, Culture=neutral, PublicKeyToken=null: Command Manager has [1] pending commands:::
LTAgent v190.138 - 5/21/2019 10:23:12 AM - Plugin ChocolateyForAutomate, Version=3.0.0.20, Culture=neutral,
LTAgent v190.138 - 5/21/2019 10:23:12 AM - Plugin ChocolateyForAutomate, Version=3.0.0.20, Culture=neutral, PublicKeyToken=null: Exectuing commands on agent ID 5835 Command = UpdateClient App = 7zip.install:::
LTAgent v190.138 - 5/21/2019 10:23:12 AM - Plugin ChocolateyForAutomate, Version=3.0.0.20, Culture=neutral, PublicKeyToken=null: Chocolatey_Command_Manager completed.:::

I'll stop there, this sequence seem to repeat itself for the other commands, both working and not working, but we can provide more if needed to troubleshoot.

In Plugin_ChocolateyForAutomate_Errors we still have the SQL error mentioned earlier but I know you are still checking that out, just for completness sake:
LTAgent v190.138 - 5/21/2019 8:09:46 AM - Plugin Error ChocolateyForAutomate, Version=3.0.0.20, Culture=neutral, PublicKeyToken=null: SetSQLColumn count doesn't match value count at row 2:::

Our server LTSQLErrors.txt has some errors regarding missing tables, but this makes sense of course since we dropped them to have them recreated (we find this reduced bloat when testing):
LTAgent v190.138 - 5/21/2019 8:10:06 AM - ESQL Table 'labtech.plugin_p4l_chocolatey_installed_apps' doesn't exist <REDACTED>:::

We also have some errors related to another plugin, that lists an invalid query involving computer names, operating system and product-keys but this does not match the timestamps or schedule of this plugin and I'm almost certain they cant be related.


Do you need any more info from us or need us to complete a sequence of actions in any specific order to help reproduce or shed light on the problems/issues?

User avatar
Cubert
Posts: 2430
Joined: Tue Dec 29, 2015 7:57 pm
8
Contact:

Re: Plugin (mostly) not working for us

Post by Cubert »

As promised here is the update.

https://delivery.shopifyapps.com/-/babb ... 3e857a4a01.


What's changed:

We added several new logging sets to better show where in a function the command is at! (Awesome right!)
We fixed the "UpdateC" issue
We also found the issue with the "X-ALL-X" functions so this should solve everything thus far. See if that changes the outcomes for you.

HenningIdrift
Posts: 4
Joined: Mon Apr 08, 2019 7:20 pm
4

Re: Plugin (mostly) not working for us

Post by HenningIdrift »

Thanks again for the update!

I can confirm UpdateClient and Update works now at least (the others probably does too, I just haven't had a chance to test more yet ).
I will look some more and probably be back with more questions later.

Thanks for all the help so far, and for the additional logging. Very helpful!

User avatar
Cubert
Posts: 2430
Joined: Tue Dec 29, 2015 7:57 pm
8
Contact:

Re: Plugin (mostly) not working for us

Post by Cubert »

We just released build 3.0.0.23 which has a few more tweaks to it.

Post Reply

Return to “Chocolatey For Labtech”