ms-iot / azure-client-tools

Azure Client Tools
Other
43 stars 37 forks source link

Invoking methods returns "Code: 183, Message: Version not found" #21

Closed thj-dk closed 5 years ago

thj-dk commented 5 years ago

I'm trying to get the Device Agent up and running, but I'm having issues invoking methods on my device. No matter what command I'm invoking, it's the same error:

Error: [DeviceAgentPlugin] Code: 183, Message: Version not found

What version? Any ideas?

It's a clean IoT Core install, with device agent configured as described in Quick start with Azure DPS.

Here's some log output:

[192.168.1.200]: PS C:\dm\logs> cat AzureDM.Core.2019_05_03_23_08_10.log
11-17-55 PM [00003704] [00001228] Microsoft::Azure::DeviceManagement::Client::AzureRawHost::OnDirectMethodInvoked
11-17-55 PM [00003704] [00001228] ---- Direct Method Start >> ---------------------------------------------------------------------------
11-17-55 PM [00003704] [00001228] Device Method Name:StartRebootCmd
11-17-55 PM [00003704] [00001228] Parameters        :null
11-17-55 PM [00003704] [00001228] Microsoft::Azure::DeviceManagement::Client::AzureRawHost::InvokeHandler
11-17-55 PM [00003704] [00001228] Looking for handler for: StartRebootCmd
11-17-55 PM [00003704] [00001228] Found handler for: StartRebootCmd
11-17-55 PM [00003704] [00001228] Microsoft::Azure::DeviceManagement::Client::OutOfProcPluginBinaryProxy::CacheHandlerState
11-17-55 PM [00003704] [00001228] [Transport Layer] Microsoft::Azure::DeviceManagement::Common::PluginNamedPipeTransport::SendAndGetResponse
11-17-55 PM [00003704] [00001228] [Transport Layer] Microsoft::Azure::DeviceManagement::Common::PluginNamedPipeTransport::Initialize
11-17-55 PM [00003704] [00001228] [Transport Layer] Microsoft::Azure::DeviceManagement::Common::PluginNamedPipeTransport::ClientInitialization
11-17-55 PM [00003704] [00001228] [Transport Layer] Microsoft::Azure::DeviceManagement::Common::PluginNamedPipeTransport::LaunchPluginHost
11-17-55 PM [00003704] [00001228] [Transport Layer] Pluginhost has been launched.
11-17-55 PM [00003704] [00001228] [Transport Layer] Monitoring thread created.
11-17-55 PM [00003704] [00001224] [Transport Layer] Microsoft::Azure::DeviceManagement::Common::PluginNamedPipeTransport::PluginHostMonitor
11-17-55 PM [00003704] [00001228] Connecting to client pipe...11-17-55 PM [00003704] [00001228] Connecting to plugin pipe...11-17-55 PM [00003704] [00001696] [Transport Layer] Microsoft::Azure::DeviceManagement::Common::PluginNamedPipeTransport::MessageHandlerWorker
11-17-55 PM [00003704] [00001228] Microsoft::Azure::DeviceManagement::Client::OutOfProcPluginBinaryProxy::SendCreatePluginRequest
11-17-55 PM [00003704] [00002216] [Transport Layer] Microsoft::Azure::DeviceManagement::Common::PluginNamedPipeTransport::ProcessRequest
11-17-55 PM [00003704] [00001228] [Transport Layer] Microsoft::Azure::DeviceManagement::Common::PluginNamedPipeTransport::SendAndGetResponse
11-17-55 PM [00003704] [00001696] [Transport Layer] Recieved a Response Message
11-17-55 PM [00003704] [00001696] [Transport Layer] Response notification sent
11-17-55 PM [00003704] [00001228] Microsoft::Azure::DeviceManagement::Client::OutOfProcPluginBinaryProxy::SendCachedHandlerState
11-17-55 PM [00003704] [00001228] Microsoft::Azure::DeviceManagement::Client::OutOfProcPluginBinaryProxy::CacheHandlerState
11-17-55 PM [00003704] [00001228] [Transport Layer] Microsoft::Azure::DeviceManagement::Common::PluginNamedPipeTransport::SendAndGetResponse
11-17-55 PM [00003704] [00001696] [Transport Layer] Recieved a Response Message
11-17-55 PM [00003704] [00001696] [Transport Layer] Response notification sent
11-17-55 PM [00003704] [00001228] Microsoft::Azure::DeviceManagement::Client::OutOfProcPluginBinaryProxy::CacheHandlerState
11-17-55 PM [00003704] [00001228] [Transport Layer] Microsoft::Azure::DeviceManagement::Common::PluginNamedPipeTransport::SendAndGetResponse
11-17-55 PM [00003704] [00001696] [Transport Layer] Recieved a Response Message
11-17-55 PM [00003704] [00001696] [Transport Layer] Response notification sent
11-17-55 PM [00003704] [00001228] Microsoft::Azure::DeviceManagement::Client::OutOfProcPluginBinaryProxy::CacheHandlerState
11-17-55 PM [00003704] [00001228] [Transport Layer] Microsoft::Azure::DeviceManagement::Common::PluginNamedPipeTransport::SendAndGetResponse
11-17-55 PM [00003704] [00001696] [Transport Layer] Recieved a Response Message
11-17-55 PM [00003704] [00001696] [Transport Layer] Response notification sent
11-17-55 PM [00003704] [00001228] Microsoft::Azure::DeviceManagement::Client::OutOfProcPluginBinaryProxy::CacheHandlerState
11-17-55 PM [00003704] [00001228] [Transport Layer] Microsoft::Azure::DeviceManagement::Common::PluginNamedPipeTransport::SendAndGetResponse
11-17-55 PM [00003704] [00001696] [Transport Layer] Recieved a Response Message
11-17-55 PM [00003704] [00001696] [Transport Layer] Response notification sent
11-17-55 PM [00003704] [00001228] Microsoft::Azure::DeviceManagement::Client::OutOfProcPluginBinaryProxy::CacheHandlerState
11-17-55 PM [00003704] [00001228] [Transport Layer] Microsoft::Azure::DeviceManagement::Common::PluginNamedPipeTransport::SendAndGetResponse
11-17-55 PM [00003704] [00001696] [Transport Layer] Recieved a Response Message
11-17-55 PM [00003704] [00001696] [Transport Layer] Response notification sent
11-17-55 PM [00003704] [00001228] Microsoft::Azure::DeviceManagement::Client::OutOfProcPluginBinaryProxy::CacheHandlerState
11-17-55 PM [00003704] [00001228] [Transport Layer] Microsoft::Azure::DeviceManagement::Common::PluginNamedPipeTransport::SendAndGetResponse
11-17-55 PM [00003704] [00001696] [Transport Layer] Recieved a Response Message
11-17-55 PM [00003704] [00001696] [Transport Layer] Response notification sent
11-17-56 PM [00003704] [00001696] [Transport Layer] Recieved a Request Message
11-17-56 PM [00003704] [00001696] [Transport Layer] Request notification sent
11-17-56 PM [00003704] [00002216] [Transport Layer] Message Processing Thread: Received new request notification
11-17-56 PM [00003704] [00002216] [Transport Layer] Microsoft::Azure::DeviceManagement::Common::PluginNamedPipeTransport::ProcessRequestMessage
11-17-56 PM [00003704] [00002216] [Transport Layer] Received reverse-invoke call. Calling reverse invoke...
11-17-56 PM [00003704] [00002216] Microsoft::Azure::DeviceManagement::Client::AzureRawHost::Report
11-17-56 PM [00003704] [00002216] Microsoft::Azure::DeviceManagement::Common::ReportedSummary::ToJsonObject
11-17-56 PM [00003704] [00002216] Microsoft::Azure::DeviceManagement::Client::AzureRawHost::ReportAll
11-17-56 PM [00003704] [00002216] Microsoft::Azure::DeviceManagement::Client::AzureRawHost::ReportAll
11-17-56 PM [00003704] [00002216] {
    "StartRebootCmd" : 
    {
        "__errors" : 
        {
            "StartRebootCmd" : 
            {
                "code" : 183,
                "context" : "StartRebootCmd",
                "message" : "Version not found",
                "parameters" : {},
                "subsystem" : "DeviceAgentPlugin"
            }
        },
        "__meta" : 
        {
            "deploymentId" : "unspecified",
            "deploymentStatus" : "failed",
            "deviceInterfaceVersion" : "",
            "time" : "2019-05-03T23:17:56"
        }
    },
    "__summary" : 
    {
        "deployments" : "",
        "failedCount" : 1,
        "failedGroups" : "StartRebootCmd",
        "pendingCount" : 0,
        "pendingGroups" : "",
        "time" : "2019-05-03T23:17:56"
    }
}

11-17-56 PM [00003704] [00002216] [Transport Layer] Reverse invoke returned with error code 0
11-17-56 PM [00003704] [00002216] [Transport Layer] Deleted ReverseInvoke buffer
11-17-56 PM [00003704] [00002216] [Transport Layer] Sending response
11-17-56 PM [00003704] [00002216] [Transport Layer] Response sent
11-17-56 PM [00003704] [00001696] [Transport Layer] Recieved a Response Message
11-17-56 PM [00003704] [00001696] [Transport Layer] Response notification sent
11-17-56 PM [00003704] [00001228] Device Method Returned->payload: {
    "code" : 183,
    "context" : "StartRebootCmd",
    "message" : "Version not found",
    "parameters" : {},
    "subsystem" : "DeviceAgentPlugin"
}

11-17-56 PM [00003704] [00001228] Device Method Returned->code: 400
11-17-56 PM [00003704] [00001228] ---- Direct Method End << -----------------------------------------------------------------------------
11-17-56 PM [00003704] [00001228] Microsoft::Azure::DeviceManagement::Client::AzureRawHost::OnReportedStateSent
11-17-56 PM [00003704] [00001228] OnReportedStateSent() - statusCode: 200
[192.168.1.200]: PS C:\dm\logs> cat AzureDM.rebootInfo.2019_05_03_23_17_55.log
11-17-55 PM [00001308] [00000456] Logging configured.
11-17-55 PM [00001308] [00000456] Microsoft::Azure::DeviceManagement::RebootPlugin::RebootStateHandler::OnConnectionStatusChanged
11-17-55 PM [00001308] [00000456] Connection Status: Online.
11-17-55 PM [00001308] [00000456] Microsoft::Azure::DeviceManagement::RebootPlugin::RebootCmdHandler::Invoke
11-17-55 PM [00001308] [00000456] Microsoft::Azure::DeviceManagement::Common::Operation::RunOperation
11-17-55 PM [00001308] [00000456] Sub-Group: StartRebootCmd
11-17-55 PM [00001308] [00000456] SubSystem              : DeviceAgentPlugin
11-17-55 PM [00001308] [00000456] Exception code         : 183
11-17-55 PM [00001308] [00000456] Exception debug message: Version not found
11-17-56 PM [00001308] [00000456] Error: [DeviceAgentPlugin] Code: 183, Message: Version not found
11-17-56 PM [00001308] [00000456] Microsoft::Azure::DeviceManagement::Common::ReportedErrorList::AddError
11-17-56 PM [00001308] [00000456] Microsoft::Azure::DeviceManagement::Common::ReportedErrorList::ToJsonObject
11-17-56 PM [00001308] [00000456] Microsoft::Azure::DeviceManagement::Common::ReportedError::ToJsonObject
11-17-56 PM [00001308] [00000456] Microsoft::Azure::DeviceManagement::Common::ReportedErrorList::ToJsonObject
11-17-56 PM [00001308] [00000456] Microsoft::Azure::DeviceManagement::Common::ReportedError::ToJsonObject
[192.168.1.200]: PS C:\dm\logs> cat AzureDM.StartRebootCmd.2019_05_03_23_17_55.log
11-17-55 PM [00001308] [00000456] Logging configured.
11-17-55 PM [00001308] [00000456] Microsoft::Azure::DeviceManagement::RebootPlugin::RebootCmdHandler::OnConnectionStatusChanged
11-17-55 PM [00001308] [00000456] Connection Status: Online.
11-17-55 PM [00001308] [00000456] Microsoft::Azure::DeviceManagement::Plugin::Common::RawHandlerStub::CreateHandler
11-17-55 PM [00001308] [00000456] Microsoft::Azure::DeviceManagement::RebootPlugin::RebootStateHandler::Start
gmileka commented 5 years ago

Hi thj-dk, There is indeed a documentation bug. The method parameters should be:

{
    "__meta": {
          "serviceInterfaceVersion": "1.0.0"
    }
}

We're fixing the documentation shortly. Apologies for the inconvenience.

thanks, george

thj-dk commented 5 years ago

Great @gmileka. Thanks alot. That sure helped :-)