My plug-in caused vms to restart

Answered
Follow
Avatar
zwq

Hi.

I develop a plugin using openvino2022.3, when start the plugin, the vms server restarts all the time.

the version of openvino is 2022.3, so I don't refer to this article https://support.networkoptix.com/hc/en-us/articles/360059676373-Open-Source-OpenVINO-Analytics-Plugin .

I create my object in DeviceAgent::pushUncompressedVideoFrame,  code like below:
bool DeviceAgent::pushUncompressedVideoFrame(const IUncompressedVideoFrame* videoFrame)
{
    if (!m_app) {
        m_app = new jvsp::AppSmokePhone(this);
        m_app->LoadModel_Async();  // call openvino load model
    }
    m_app->HandleFrame();
}
the code will cause vms restart all the time.  and pushUncompressedVideoFrame is called only once, In this call, it is not stuck and only 184us is used
If I comment out "LoadModel_Async", vms do not restart, although plugin can do nothine
 
The logs of VMS are as follows:

2023-04-25 02:30:45.835 475201   DEBUG nx::vms::server::StorageManagerHelper: Candidate: 'url: '/opt/networkoptix/mediaserver/var/data', total: 116856631296, free: 47927017472, reserved: 11685663129, nxOccupied: 41874270687, available: 105170968167, effective: 78115625030, isSystem: 1'. 
2023-04-25 02:30:45.835 475201   DEBUG nx::vms::server::StorageManagerHelper: Candidate: 'url: '/opt/networkoptix/mediaserver/var/data', total: 116856631296, free: 47927013376, reserved: 11685663129, nxOccupied: 41874270687, available: 105170968167, effective: 78115620934, isSystem: 1'. 
2023-04-25 02:30:45.836 475201   DEBUG QnStorageManager(0x7f1428044530): [Cleanup, measure]: 1 storages are ready for a cleanup, Role: 'main'
2023-04-25 02:30:45.836 475201   DEBUG QnStorageManager(0x7f1428044530): [Cleanup, measure]: before cleanup: storage: '/opt/networkoptix/mediaserver/var/data' spaceLimit: 11685663129, remove capability: true
2023-04-25 02:30:45.836 475201   DEBUG QnStorageManager(0x7f1428044530): [Cleanup, measure]: Total bytes to cleanup: 0 (0 Mb) (0 Gb)
2023-04-25 02:30:45.836 475201   DEBUG QnStorageManager(0x7f1428044530): Cleanup. Starting for Storage /opt/networkoptix/mediaserver/var/data. -34562 MB to clean
2023-04-25 02:30:45.836 475201   DEBUG QnStorageManager(0x7f1428044530): [Cleanup] clearOldestSpace: interrupting. Storage: /opt/networkoptix/mediaserver/var/data, has catalog to delete from: true, catalog is empty: false
2023-04-25 02:30:45.836 475201   DEBUG QnStorageManager(0x7f1428044530): [Cleanup, measure]: Cleanup routine for role 'main ' has finished. Elapsed 1s (0hrs). Cleanup speed: 0Mb/s
2023-04-25 02:30:45.836 475201   DEBUG QnStorageManager(0x7f14280461c0): [Cleanup, measure]: 0 storages are ready for a cleanup, Role: 'backup'
2023-04-25 02:30:45.836 475201   DEBUG QnStorageManager(0x7f14280461c0): [Cleanup, measure]: Total bytes to cleanup: 0 (0 Mb) (0 Gb)
2023-04-25 02:30:45.836 475201   DEBUG QnStorageManager(0x7f14280461c0): [Cleanup, measure]: Cleanup routine for role 'backup' has finished. Elapsed 1s (0hrs). Cleanup speed: 0Mb/s
2023-04-25 02:30:46.337 475096   DEBUG nx::network::ssl::AcceptingPipeline(0x7f1440044e20): SSL fatal error 336151574. error:14094416:SSL routines:ssl3_read_bytes:sslv3 alert certificate unknown
2023-04-25 02:30:46.340 475354   DEBUG nx::vms::server::auth::SessionManager(0x7f14281d38c0): Token vms-8b0006463112c83f890bcb3b1e54649c-oHbSUAxUJb is updating
2023-04-25 02:30:46.340 475354   DEBUG nx::vms::server::auth::SessionManager(0x7f14281d38c0): Token vms-8b0006463112c83f890bcb3b1e54649c-oHbSUAxUJb is updated to Default({99cbc715-539b-4bfe-856f-799b45b69b1e}, vms-8b0006463112c83f890bcb3b1e54649c-oHbSUAxUJb, 8050341ms old, for 2583949659ms)
2023-04-25 02:30:46.349 475097   DEBUG nx::network::ssl::AcceptingPipeline(0x7f1434053250): SSL fatal error 336151574. error:14094416:SSL routines:ssl3_read_bytes:sslv3 alert certificate unknown
2023-04-25 02:30:46.352 475356   DEBUG nx::vms::server::auth::Authenticator(0x7f14281d3820): Auth_OK with digest (GET /ec2/getAccessRights HTTP/1.1)
2023-04-25 02:30:46.356 475357   DEBUG nx::vms::server::auth::Authenticator(0x7f14281d3820): Auth_OK with digest (GET /ec2/getCamerasEx HTTP/1.1)
2023-04-25 02:30:46.359 475358   DEBUG nx::vms::server::auth::Authenticator(0x7f14281d3820): Auth_OK with digest (GET /ec2/getUserRoles HTTP/1.1)
2023-04-25 02:30:46.363 475359   DEBUG nx::vms::server::auth::Authenticator(0x7f14281d3820): Auth_OK with digest (GET /ec2/getPredefinedRoles HTTP/1.1)
2023-04-25 02:30:46.363 475360   DEBUG nx::vms::server::auth::Authenticator(0x7f14281d3820): Auth_OK with digest (GET /ec2/getTimeOfServers HTTP/1.1)
2023-04-25 02:30:46.366 475362   DEBUG nx::vms::server::auth::Authenticator(0x7f14281d3820): Auth_OK with digest (GET /ec2/getUsers HTTP/1.1)
2023-04-25 02:30:46.370 475363   DEBUG nx::vms::server::auth::Authenticator(0x7f14281d3820): Auth_OK with digest (GET /ec2/getMediaServersEx HTTP/1.1)
2023-04-25 02:30:46.381 475355   DEBUG nx::vms::server::analytics::Manager(0x7f142804b4f0): Collecting Engine binding info
2023-04-25 02:30:46.382 475355   DEBUG nx::vms::utils::metrics::SystemController(0x7f142813c820): Return 2 cameras, 2 networkInterfaces, 1 servers, 1 storages, 1 systems from system values in 863005ns
2023-04-25 02:30:46.394 475365   DEBUG nx::vms::server::auth::Authenticator(0x7f14281d3820): Auth_OK with digest (GET /ec2/getCamerasEx HTTP/1.1)
2023-04-25 02:30:46.398 475366   DEBUG nx::vms::server::auth::Authenticator(0x7f14281d3820): Auth_OK with digest (GET /ec2/getTimeOfServers HTTP/1.1)
2023-04-25 02:30:46.404 475355   DEBUG nx::vms::server::analytics::Manager(0x7f142804b4f0): Collecting Engine binding info
2023-04-25 02:30:46.405 475355   DEBUG nx::vms::utils::metrics::SystemController(0x7f142813c820): Return 2 cameras, 2 networkInterfaces, 1 servers, 1 storages, 1 systems from system values in 980521ns
2023-04-25 02:30:46.479 475106   DEBUG nx::monitoring::InterfaceStatisticsContext: Failed to get NIC speed, assuming 1Gbps
2023-04-25 02:30:48.480 475106   DEBUG nx::monitoring::InterfaceStatisticsContext: Failed to get NIC speed, assuming 1Gbps
2023-04-25 02:30:49.010 475096   DEBUG nx::vms::server::auth::SessionManager(0x7f14281d38c0): Token vms-8b0006463112c83f890bcb3b1e54649c-QvR03ANU3F is updated to Default({99cbc715-539b-4bfe-856f-799b45b69b1e}, vms-8b0006463112c83f890bcb3b1e54649c-QvR03ANU3F, 8995011ms old, for 2583004989ms)
2023-04-25 02:30:50.480 475106   DEBUG nx::monitoring::InterfaceStatisticsContext: Failed to get NIC speed, assuming 1Gbps
2023-04-25 02:30:51.069 475203   DEBUG QnMServerResourceDiscoveryManager(0x7f14280181c0): Network addresses are up to date: { 172.16.42.230, fe80::95d3:41d5:ea60:b51b%3 }
2023-04-25 02:30:51.070 475203   DEBUG ThirdPartyResourceSearcher(0x7f142832aae0): Found 0 mdns, 0 upnp and 0 customSearch resources
2023-04-25 02:30:51.070 475203   DEBUG QnMServerResourceDiscoveryManager(0x7f14280181c0): Searcher THIRD_PARTY took 0 ms to find 0 resources
2023-04-25 02:30:51.070 475203   DEBUG QnMServerResourceDiscoveryManager(0x7f14280181c0): Searcher C2pCamera took 0 ms to find 0 resources
2023-04-25 02:30:51.070 475203   DEBUG QnMServerResourceDiscoveryManager(0x7f14280181c0): Searcher DESKTOP_CAMERA took 0 ms to find 1 resources
2023-04-25 02:30:51.070 475203   DEBUG QnMServerResourceDiscoveryManager(0x7f14280181c0): Searcher VIRTUAL_CAMERA took 0 ms to find 0 resources
2023-04-25 02:30:51.070 475203   DEBUG QnMServerResourceDiscoveryManager(0x7f14280181c0): Searcher NetworkOptix took 0 ms to find 0 resources
2023-04-25 02:30:51.220 475203   DEBUG QnMServerResourceDiscoveryManager(0x7f14280181c0): Searcher ArecontVision took 150 ms to find 0 resources
2023-04-25 02:30:51.371 475203   DEBUG QnMServerResourceDiscoveryManager(0x7f14280181c0): Searcher Dlink took 150 ms to find 0 resources
2023-04-25 02:30:51.371 475203   DEBUG QnMServerResourceDiscoveryManager(0x7f14280181c0): Searcher Axis took 0 ms to find 0 resources
2023-04-25 02:30:51.371 475203   DEBUG QnMServerResourceDiscoveryManager(0x7f14280181c0): Searcher ACTI took 0 ms to find 0 resources
2023-04-25 02:30:51.626 475369   DEBUG nx::vms::server::auth::SessionManager(0x7f14281d38c0): Token {d52d2547-1eef-4da5-a146-0d04f6e88201} was cached 12561334558ns ago with bad result, dropping cache
2023-04-25 02:30:51.626 475369   DEBUG nx::vms::server::auth::SessionManager(0x7f14281d38c0): Token {d52d2547-1eef-4da5-a146-0d04f6e88201} is fetching
2023-04-25 02:30:51.626 475369   DEBUG nx::vms::server::auth::SessionManager(0x7f14281d38c0): Token {d52d2547-1eef-4da5-a146-0d04f6e88201} is updated to Error[TokenNotFound: Unsupported token format]
2023-04-25 02:30:51.626 475370   DEBUG ec2::UpdateHttpHandler<std::vector<nx::vms::api::ResourceParamWithRefData, std::allocator<nx::vms::api::ResourceParamWithRefData> >, std::vector<nx::vms::api::ResourceParamWithRefData, std::allocator<nx::vms::api::ResourceParamWithRefData> >, ec2::BaseEc2Connection<ec2::ServerQueryProcessorAccess> >(0x7f142854b780): Received transaction setResourceParams via ec2 http request. Data: [N2nx3vms3api24ResourceParamWithRefDataE]
2023-04-25 02:30:51.626 475369   DEBUG ec2::UpdateHttpHandler<std::vector<nx::vms::api::CameraAttributesData, std::allocator<nx::vms::api::CameraAttributesData> >, std::vector<nx::vms::api::CameraAttributesData, std::allocator<nx::vms::api::CameraAttributesData> >, ec2::BaseEc2Connection<ec2::ServerQueryProcessorAccess> >(0x7f1428533100): Received transaction saveCameraUserAttributesList via ec2 http request. Data: [N2nx3vms3api20CameraAttributesDataE]
2023-04-25 02:30:51.628 475119   DEBUG nx::vms::server::analytics::DeviceAnalyticsBinding(0x7f13e8007e10): Creating a DeviceAgent for the Device UnknownIPC ({2bc706b0-635c-bb63-4ce9-0fd32cb67eb3})
2023-04-25 02:30:51.636 475119   DEBUG nx::vms::server::analytics::DeviceAnalyticsBinding(0x7f13e8007e10): Initializing settings context, the model from the Device and Engine manifests: {}. Device: nx::vms::server::plugins::onvif::Resource(0x7f14286f4830, E0-62-90-66-2D-07), Engine: nx::vms::server::resource::AnalyticsEngineResource(0x7f14286fe8a0, [SmokePhone {76e648ad-9124-56de-be38-2f411dcd7f15}])
2023-04-25 02:30:51.636 475119   DEBUG nx::vms::server::analytics::DeviceAnalyticsBinding(0x7f13e8007e10): Settings context has been initialized, model: {}, model id: {99914b93-2bd3-7a50-b983-c5e7c90ae93b}, values: {},saveSettingsValuesToProperty: true, Device: %5, Engine: %6
2023-04-25 02:30:51.636 475119   DEBUG nx::vms::server::analytics::DeviceAnalyticsBinding(0x7f13e8007e10): Pixel format is specified but no stream type filter is defined in the manifest of the Engine SmokePhone ({76e648ad-9124-56de-be38-2f411dcd7f15}). Adding `uncompressedVideo` stream type to requirements. Device: UnknownIPC ({2bc706b0-635c-bb63-4ce9-0fd32cb67eb3})
2023-04-25 02:30:51.636 475119   DEBUG nx::vms::server::analytics::DeviceAnalyticsBinding(0x7f13e8007e10): Setting settings, settings values: {}, settings model id: {99914b93-2bd3-7a50-b983-c5e7c90ae93b}, isInitialSettings: true, Device: nx::vms::server::plugins::onvif::Resource(0x7f14286f4830, E0-62-90-66-2D-07), Engine: nx::vms::server::resource::AnalyticsEngineResource(0x7f14286fe8a0, [SmokePhone {76e648ad-9124-56de-be38-2f411dcd7f15}])
2023-04-25 02:30:51.637 475119   DEBUG nx::vms::server::analytics::DeviceAnalyticsBinding(0x7f13e8007e10): Updating settings context, current settings model: {}, current settings model id: {99914b93-2bd3-7a50-b983-c5e7c90ae93b}, settings values from the request: {}, settings model from the SDK response: <null>, settings values from the SDK response: <null> Device: nx::vms::server::plugins::onvif::Resource(0x7f14286f4830, E0-62-90-66-2D-07), Engine: nx::vms::server::resource::AnalyticsEngineResource(0x7f14286fe8a0, [SmokePhone {76e648ad-9124-56de-be38-2f411dcd7f15}])
2023-04-25 02:30:51.637 475119   DEBUG nx::vms::server::analytics::DeviceAnalyticsBinding(0x7f13e8007e10): Updating settings context, resulting settings values: {}, Device: nx::vms::server::plugins::onvif::Resource(0x7f14286f4830, E0-62-90-66-2D-07), Engine: nx::vms::server::resource::AnalyticsEngineResource(0x7f14286fe8a0, [SmokePhone {76e648ad-9124-56de-be38-2f411dcd7f15}])
2023-04-25 02:30:51.637 475119   DEBUG nx::vms::server::analytics::DeviceAnalyticsBinding(0x7f13e8007e10): Saving settings values to property, Device: nx::vms::server::plugins::onvif::Resource(0x7f14286f4830, E0-62-90-66-2D-07), Engine nx::vms::server::resource::AnalyticsEngineResource(0x7f14286fe8a0, [SmokePhone {76e648ad-9124-56de-be38-2f411dcd7f15}])
2023-04-25 02:30:51.637 475119   DEBUG nx::vms::server::analytics::DeviceAnalyticsBinding(0x7f13e8007e10): Resulting settings response, settings model: {"filledCheckItems":[],"items":[],"type":"Settings"}, settings model id: {99914b93-2bd3-7a50-b983-c5e7c90ae93b}, settings values: {}, settings errors: none, session id: {e23b9504-1e8c-4078-8b4a-7a1382f65a60}, sequence number: 0, Device: nx::vms::server::plugins::onvif::Resource(0x7f14286f4830, E0-62-90-66-2D-07), Engine: nx::vms::server::resource::AnalyticsEngineResource(0x7f14286fe8a0, [SmokePhone {76e648ad-9124-56de-be38-2f411dcd7f15}])
2023-04-25 02:30:51.637 475119   DEBUG nx::vms::server::analytics::DeviceAnalyticsBinding(0x7f13e8007e10): Fetching needed metadata types from RuleWatcher for the Device UnknownIPC ({2bc706b0-635c-bb63-4ce9-0fd32cb67eb3})
2023-04-25 02:30:51.637 475119   DEBUG nx::vms::server::analytics::DeviceAnalyticsBinding(0x7f13e8007e10): Needed event types for the Device UnknownIPC ({2bc706b0-635c-bb63-4ce9-0fd32cb67eb3}) from RuleWatcher: none
2023-04-25 02:30:51.637 475119   DEBUG nx::vms::server::analytics::DeviceAnalyticsBinding(0x7f13e8007e10): Filtered needed event types list for resource UnknownIPC ({2bc706b0-635c-bb63-4ce9-0fd32cb67eb3}): none
2023-04-25 02:30:51.670 475235   DEBUG nx::vms::server::plugins::onvif::StreamReader(0x7f1428801460): Unable to get decoded frame for metadata plugins, compressed frame timestamp: 1682404251690000 us, Device: nx::vms::server::plugins::onvif::Resource(0x7f14286f4830, E0-62-90-66-2D-07), role: CR_LiveVideo
2023-04-25 02:30:51.672 475203   DEBUG QnMServerResourceDiscoveryManager(0x7f14280181c0): Searcher IqEye took 300 ms to find 0 resources
2023-04-25 02:30:51.672 475203   DEBUG QnPlISDResourceSearcher(0x7f142859ceb0): Found resources: 0 UPnP + 0 MDNS = 0 total
2023-04-25 02:30:51.672 475203   DEBUG QnMServerResourceDiscoveryManager(0x7f14280181c0): Searcher ISD took 0 ms to find 0 resources
2023-04-25 02:30:51.672 475203   DEBUG QnMServerResourceDiscoveryManager(0x7f14280181c0): Searcher Hanwha Techwin took 0 ms to find 0 resources
2023-04-25 02:30:51.679 475235   DEBUG nx::vms::server::plugins::onvif::StreamReader(0x7f1428801460): Unable to get decoded frame for metadata plugins, compressed frame timestamp: 1682404251730000 us, Device: nx::vms::server::plugins::onvif::Resource(0x7f14286f4830, E0-62-90-66-2D-07), role: CR_LiveVideo
2023-04-25 02:30:51.720 475235   DEBUG nx::vms::server::plugins::onvif::StreamReader(0x7f1428801460): Unable to get decoded frame for metadata plugins, compressed frame timestamp: 1682404251770000 us, Device: nx::vms::server::plugins::onvif::Resource(0x7f14286f4830, E0-62-90-66-2D-07), role: CR_LiveVideo
2023-04-25 02:30:51.761 475235   DEBUG nx::vms::server::plugins::onvif::StreamReader(0x7f1428801460): Unable to get decoded frame for metadata plugins, compressed frame timestamp: 1682404251810000 us, Device: nx::vms::server::plugins::onvif::Resource(0x7f14286f4830, E0-62-90-66-2D-07), role: CR_LiveVideo
2023-04-25 02:30:51.801 475235   DEBUG nx::vms::server::plugins::onvif::StreamReader(0x7f1428801460): Unable to get decoded frame for metadata plugins, compressed frame timestamp: 1682404251850000 us, Device: nx::vms::server::plugins::onvif::Resource(0x7f14286f4830, E0-62-90-66-2D-07), role: CR_LiveVideo
2023-04-25 02:30:51.842 475235   DEBUG nx::vms::server::plugins::onvif::StreamReader(0x7f1428801460): Unable to get decoded frame for metadata plugins, compressed frame timestamp: 1682404251890000 us, Device: nx::vms::server::plugins::onvif::Resource(0x7f14286f4830, E0-62-90-66-2D-07), role: CR_LiveVideo
2023-04-25 02:30:51.882 475235   DEBUG nx::vms::server::plugins::onvif::StreamReader(0x7f1428801460): Unable to get decoded frame for metadata plugins, compressed frame timestamp: 1682404251930000 us, Device: nx::vms::server::plugins::onvif::Resource(0x7f14286f4830, E0-62-90-66-2D-07), role: CR_LiveVideo
2023-04-25 02:30:51.923 475235   DEBUG nx::vms::server::plugins::onvif::StreamReader(0x7f1428801460): Unable to get decoded frame for metadata plugins, compressed frame timestamp: 1682404251970000 us, Device: nx::vms::server::plugins::onvif::Resource(0x7f14286f4830, E0-62-90-66-2D-07), role: CR_LiveVideo
2023-04-25 02:30:51.963 475235   DEBUG nx::vms::server::plugins::onvif::StreamReader(0x7f1428801460): Unable to get decoded frame for metadata plugins, compressed frame timestamp: 1682404252010000 us, Device: nx::vms::server::plugins::onvif::Resource(0x7f14286f4830, E0-62-90-66-2D-07), role: CR_LiveVideo
2023-04-25 02:30:52.015 475235   DEBUG nx::vms::server::plugins::onvif::StreamReader(0x7f1428801460): Unable to get decoded frame for metadata plugins, compressed frame timestamp: 1682404252050000 us, Device: nx::vms::server::plugins::onvif::Resource(0x7f14286f4830, E0-62-90-66-2D-07), role: CR_LiveVideo
2023-04-25 02:30:52.035 475235   DEBUG nx::vms::server::plugins::onvif::StreamReader(0x7f1428801460): Unable to get decoded frame for metadata plugins, compressed frame timestamp: 1682404252090000 us, Device: nx::vms::server::plugins::onvif::Resource(0x7f14286f4830, E0-62-90-66-2D-07), role: CR_LiveVideo
2023-04-25 02:30:52.056 475105    INFO nx::vms::server::VideoCamera(0x7f1428771bc0): Enabling Live Cache for primary stream (30000..50000 milliseconds): useful because analytics produces objects
2023-04-25 02:30:52.056 475105   DEBUG nx::vms::server::plugins::onvif::StreamReader(0x7f1428801460): Add data processor: MediaStreamCache(0x7f1428625c30)
2023-04-25 02:30:52.086 475235   DEBUG nx::vms::server::plugins::onvif::StreamReader(0x7f1428801460): Unable to get decoded frame for metadata plugins, compressed frame timestamp: 1682404252130000 us, Device: nx::vms::server::plugins::onvif::Resource(0x7f14286f4830, E0-62-90-66-2D-07), role: CR_LiveVideo
2023-04-25 02:30:52.116 475235   DEBUG nx::vms::server::plugins::onvif::StreamReader(0x7f1428801460): Unable to get decoded frame for metadata plugins, compressed frame timestamp: 1682404252170000 us, Device: nx::vms::server::plugins::onvif::Resource(0x7f14286f4830, E0-62-90-66-2D-07), role: CR_LiveVideo
2023-04-25 02:30:52.158 475235   DEBUG nx::vms::server::plugins::onvif::StreamReader(0x7f1428801460): Unable to get decoded frame for metadata plugins, compressed frame timestamp: 1682404252210000 us, Device: nx::vms::server::plugins::onvif::Resource(0x7f14286f4830, E0-62-90-66-2D-07), role: CR_LiveVideo
2023-04-25 02:30:52.172 475203   DEBUG QnMServerResourceDiscoveryManager(0x7f14280181c0): Searcher AdvantechADAM took 500 ms to find 0 resources
2023-04-25 02:30:52.173 475203   DEBUG QnMServerResourceDiscoveryManager(0x7f14280181c0): Searcher FLIR_FC took 0 ms to find 0 resources
2023-04-25 02:30:52.173 475203   DEBUG QnMServerResourceDiscoveryManager(0x7f14280181c0): Searcher FLIR took 0 ms to find 0 resources
2023-04-25 02:30:52.173 475203   DEBUG QnMServerResourceDiscoveryManager(0x7f14280181c0): Searcher ARCHIVE_CAMERA took 0 ms to find 0 resources
2023-04-25 02:30:52.173 475203   DEBUG QnMServerResourceDiscoveryManager(0x7f14280181c0): Searcher OnvifDevice took 0 ms to find 0 resources
2023-04-25 02:30:52.175 475203   DEBUG QnMServerResourceDiscoveryManager(0x7f14280181c0): Searcher OnvifDevice took 2 ms to find 2 resources
2023-04-25 02:30:52.176 475212   DEBUG nx::vms::server::plugins::onvif::Resource(0x7f1428612670, E0-62-90-66-4E-E9): Start initializing for resource {e4783cfc-59f6-c584-678e-da6b7c4a3d05}
2023-04-25 02:30:52.210 475212   DEBUG nx::vms::server::plugins::onvif::soap::Session(0x7f13a67bb590, http://172.16.42.89:80/onvif/device_service): Failed to call Device/GetDeviceInformation at http://172.16.42.89:80/onvif/device_service: Fault info. Reason: Incorrect Account or Password. Additional: SOAP-ENV:Sender. Sub info: "http://www.onvif.org/ver10/error":NotAuthorized. Additional details: <SOAP-ENV:Text xml:lang="en">You still have 13 opportunities. After 20 consecutive input errors, the account will be locked for 20 seconds.</SOAP-ENV:Text>
            . 
2023-04-25 02:30:52.210 475212   DEBUG nx::vms::server::plugins::onvif::Resource(0x7f1428612670, E0-62-90-66-4E-E9): SOAP request failed.  Caller = updateFirmware(), Device = NVT-GK7205v200-4Inches-4GJOVISION, id = {e4783cfc-59f6-c584-678e-da6b7c4a3d05}, url = http://172.16.42.89:80/onvif/device_service, request command = GetDeviceInformation, error = 1 ("Fault info. Reason: Incorrect Account or Password. Additional: SOAP-ENV:Sender. Sub info: "http://www.onvif.org/ver10/error":NotAuthorized. Additional details: <SOAP-ENV:Text xml:lang="en">You still have 13 opportunities. After 20 consecutive input errors, the account will be locked for 20 seconds.</SOAP-ENV:Text>
            . ") (timeout=22ms)
2023-04-25 02:30:52.210 475212   DEBUG nx::vms::server::plugins::onvif::Resource(0x7f1428612670, E0-62-90-66-4E-E9): Initializing camera driver done. Camera E0-62-90-66-4E-E9. It took 34ms
2023-04-25 02:30:52.211 475212   DEBUG nx::vms::server::plugins::onvif::Resource(0x7f1428612670, E0-62-90-66-4E-E9): Initialization finished for resource {e4783cfc-59f6-c584-678e-da6b7c4a3d05} with result: Not authorized. URL http://172.16.42.89:80/onvif/device_service.
2023-04-25 02:30:52.244 475235   DEBUG QnFfmpegVideoDecoder(0x7f13d801ae90): Initialize video decoder, codec id: 27, thread count: 1
2023-04-25 02:30:52.940 475407    INFO START: ================================================================================
2023-04-25 02:30:52.940 475407    INFO START: Network Optix Media Server started, version: 5.0.0.36634, revision: 6bbabddffb5d
2023-04-25 02:30:52.940 475407    INFO START: Binary path: /opt/networkoptix/mediaserver/bin/mediaserver
2023-04-25 02:30:52.940 475407    INFO START: Log level: info
2023-04-25 02:30:52.940 475407    INFO START: Log file size: 10M, backup count: 25, file: /opt/networkoptix/mediaserver/var/log/log_file.log
2023-04-25 02:30:52.940 475407    INFO START: Mutex implementation: qt
2023-04-25 02:30:52.940 475407    INFO MediaServerProcess(0x561aee24e330): IniConfig iniFilesDir: /home/networkoptix/.config/nx_ini/
 
 
 
0

Comments

11 comments

Sort by Date Votes
  • Avatar
    Andrey Terentyev

    Hello,

    pushUncompressedVideoFrame() is called per every frame receive by the Server. That means LoadModel_Async() called multiple times causing the model to be loaded/reloaded multiple times at the rate of current stream FPS.

    pushUncompressedVideoFrame() is not a proper place for any initialization procedures like loading models, reading config file etc, which are supposed to be done once.

    I'd suggest placing LoadModel_Async() to the DeviceAgent constructor.

    Another and better option would be loading the model in the m_app member constructor.

    0
    Comment actions Permalink
  • Avatar
    zwq

    Thank you very much for your reply
    In fact, pushUncompressedVideoFrame() is called only once, and LoadModel_Async() called once too
    I tried placing LoadModel_Async() to the DeviceAgent constructor, the vms restarts as the same
    I wonder if vms has loaded other versions of the openvino library, which conflicts with my openvino2022.3

    0
    Comment actions Permalink
  • Avatar
    Andrey Terentyev

    Hi,

    I tried placing LoadModel_Async() to the DeviceAgent constructor, the vms restarts as the same

    Obviously, there is something inside the LoadModel_Async() method that crashes and causes the Server to restart.

    Try to comment step-by-step the code inside the method to find out which part of code or function causes the crash.

    I wonder if vms has loaded other versions of the openvino library, which conflicts with my openvino2022.3

    Out of the box, VMS does not have openvino library.

    For troubleshooting, you could search server log files for messages having the PluginManager string.

    I guess the plugin binary just can't find the openvino library in the OS.

    How have you installed the openvino library? Have you refactored the project and indicated openvino header file locations, library binary locations?

    Have you read our developer guide and tried to build opencv plugin?

    https://meta.nxvms.com/docs/developers/knowledgebase/200-introduction-to-creating-a-video-analytics-plugin

    Could you provide OS version, Metadata SDK version?

    Could you share your project code?

     

    0
    Comment actions Permalink
  • Avatar
    zwq
    • Edited

    Hi, I'm sorry for the late reply because of the holiday.

    Obviously, there is something inside the LoadModel_Async() method that crashes and causes the Server to restart.
    Try to comment step-by-step the code inside the method to find out which part of code or function causes the crash.

    You are right, my plugin crashed at ov::Core::Core,
    I find an core.xxxx in /opt/networkoptix/mediaserver/bin, bt info as below:

        Program terminated with signal SIGABRT, Aborted.
        #0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
        50    ../sysdeps/unix/sysv/linux/raise.c: 没有那个文件或目录.
        [Current thread is 1 (Thread 0x7f453a73b700 (LWP 14693))]
        (gdb) bt
        #0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
        #1  0x00007f45ee9b8859 in __GI_abort () at abort.c:79
        #2  0x00007f45eee59c20 in __gnu_cxx::__verbose_terminate_handler ()
            at /home/jenkins/conan-build-2/.conan/data/gcc-toolchain/10.2/_/_/build/f24d9d4a49445fd389b06d3f22addc2784700473/.build/x86_64-linux-gnu/src/gcc/libstdc++-v3/libsupc++/vterminate.cc:95
        #3  0x00007f45eee583bd in __cxxabiv1::__terminate (handler=<optimized out>)
            at /home/jenkins/conan-build-2/.conan/data/gcc-toolchain/10.2/_/_/build/f24d9d4a49445fd389b06d3f22addc2784700473/.build/x86_64-linux-gnu/src/gcc/libstdc++-v3/libsupc++/eh_terminate.cc:48
        #4  0x00007f45eee583ff in std::terminate ()
            at /home/jenkins/conan-build-2/.conan/data/gcc-toolchain/10.2/_/_/build/f24d9d4a49445fd389b06d3f22addc2784700473/.build/x86_64-linux-gnu/src/gcc/libstdc++-v3/libsupc++/eh_terminate.cc:58
        #5  0x00007f45eee585e8 in __cxxabiv1::__cxa_throw (obj=0x7f455800c150, tinfo=0x7f45d47cd0c8, 
            dest=0x7f457e8ff9e0)
            at /home/jenkins/conan-build-2/.conan/data/gcc-toolchain/10.2/_/_/build/f24d9d4a49445fd389b06d3f22addc2784700473/.build/x86_64-linux-gnu/src/gcc/libstdc++-v3/libsupc++/eh_throw.cc:95
        #6  0x00007f457e8619cb in ?? ()
           from /opt/networkoptix/mediaserver/bin/plugins/JVSmokePhone_analytics_plugin/libopenvino.so.2230
        #7  0x00007f457effe65d in ov::Core::Core(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&) ()
           from /opt/networkoptix/mediaserver/bin/plugins/JVSmokePhone_analytics_plugin/libopenvino.so.2230
        #8  0x00007f45d419afdb in ?? ()
        #9  0x00007f455800a890 in ?? ()
        #10 0x00007f455800a880 in ?? ()
        #11 0x00007f45d47da480 in ?? ()
        #12 0x00007f4558009c40 in ?? ()
        #13 0x00007f453a73a730 in ?? ()
        #14 0x0000000000000000 in ?? ()

    How have you installed the openvino library? Have you refactored the project and indicated openvino header file locations, library binary locations?

    There are four files in the attachment:
    1 App_SmokePhone.tgz
    2 JVSmokePhone_analytics_plugin.tgz
    3 core.1683170987
    4 metadata_sdk.zip : plugin source code

    1&2 is the plugin, you can install as below:
    cd /opt
    tar zxf App_SmokePhone.tgz
    tar zxf JVSmokePhone_analytics_plugin.tgz
    sudo cp JVSmokePhone_analytics_plugin /opt/networkoptix/mediaserver/bin/plugins/ -rfp
    sudo service networkoptix-mediaserver restart

    4 is plugin source code, my code is in metadata_sdk/samples/App_SmokePhone:

     


    Have you read our developer guide and tried to build opencv plugin?
    https://meta.nxvms.com/docs/developers/knowledgebase/200-introduction-to-creating-a-video-analytics-plugin

    no, This document was not found before
    I compiled with the default g++9. Switch to g++8 according to the documentation, and the problem remains

    Could you provide OS version, Metadata SDK version?

    OS: Linux mix 5.15.0-71-generic #78~20.04.1-Ubuntu SMP Wed Apr 19 11:26:48 UTC 2023 x86_64 x86_64 x86_64 GNU/Linux
    Metadata SDK: nxwitness-server-5.0.0.36634-linux_x64.deb

    Could you share your project code?

    yes

    Attachment:

        https://pan.baidu.com/s/1RT6FlcYpKHRDJnEOs9p9nQ?pwd=nhp3 
        code：nhp3

     

    0
    Comment actions Permalink
  • Avatar
    Andrey Terentyev
    • Edited

    Hello,

    Could you please relocate your archive to another cloud storage? For downloading the file, gaidu requires baidu network disk to be installed, which is not something I'd like to do.

    0
    Comment actions Permalink
  • Avatar
    zwq

    https://drive.google.com/file/d/15bpC4DVvzNA6arz5Q6igADA1rcDKm1BN/view?usp=share_link

    0
    Comment actions Permalink
  • Avatar
    Andrey Terentyev
    • Edited

    Hello,

    I got your materials. Thanks.

    I copied the JVSmokePhone_analytics_plugin to the Server and restarted the Server. Here is what I see in

    /opt/networkoptix/mediaserver/var/log/log_file.log

    2023-05-05 16:02:25.889 1203745   INFO PluginManager(0x7f73240493a0): Considering to load Server plugin [/opt/networkoptix/mediaserver/bin/plugins/JVSmokePhone_analytics_plugin/libJVSmokePhone_analytics_plugin.so]
    2023-05-05 16:02:25.890 1203745   ERROR PluginManager(0x7f73240493a0): Failed loading Server Plugin [/opt/networkoptix/mediaserver/bin/plugins/JVSmokePhone_analytics_plugin/libJVSmokePhone_analytics_plugin.so] (): [cannotLoadLibrary]: Cannot load library /opt/networkoptix/mediaserver/bin/plugins/JVSmokePhone_analytics_plugin/libJVSmokePhone_analytics_plugin.so: (libpugixml.so.1: cannot open shared object file: No such file or directory)

    Your plugin is missing a dependency (the libpugixml library), which should be placed in the same directory the plugin binary resides, i.e. JVSmokePhone_analytics_plugin.

    0
    Comment actions Permalink
  • Avatar
    zwq
    • Edited

    Hi

    Sorry for that, my device has installed OpenVINO SDK, so it's not clean. 
    on the dirty device, the plugin can find libpugixml.so in /usr/lib/x86_64-linux-gnu/, which is installed by OpenVINO SDK.

    You can download the patch and then install it by the following steps:
    https://drive.google.com/file/d/1lYTnRb6fZa-R24OPeeEjySPHAxxpdtQi/view?usp=share_link

    sudo tar xf JVSmokePhone_analytics_plugin.patch.tar -C /opt/networkoptix/mediaserver/bin/plugins/JVSmokePhone_analytics_plugin/
    sudo service networkoptix-mediaserver restart

    Then vms restarts all the time

    0
    Comment actions Permalink
  • Avatar
    Andrey Terentyev

    Hello,

    I have investigated your code.

    Please, follow the recommendations given above.

    https://support.networkoptix.com/hc/en-us/community/posts/14135390034583/comments/14190278658711

    I'll try to explain using your code. Here it is.

    /**
     * Called when the Server sends a new uncompressed frame from a camera.
     */
    bool DeviceAgent::pushUncompressedVideoFrame(const IUncompressedVideoFrame* videoFrame)
    {
        ++m_frameIndex;
        m_lastVideoFrameTimestampUs = videoFrame->timestampUs();

        uint64_t ts_begin = jvnn::CTool::GetTimeStapUs();
        if (!m_app) {
            m_app = new jvsp::AppSmokePhone(this);
            int planeCount = videoFrame->planeCount();
            int lineSize0 = videoFrame->lineSize(0);
            int width = videoFrame->width();
            int height = videoFrame->height();
            nnDbg(NN_LOG, "creating app, frame info: wh=%d*%d, planeCount=%d, lineSize(0)=%d\n", width, height, planeCount, lineSize0);
            if (planeCount == 1 && lineSize0 == width * 3) {
                m_app->SetFrameInfo(width, height);
                m_app->LoadModel_Async();
            } else {
                nnDbg(NN_ERR, "unsupport image format, planeCount != 1 || lineSize0 != width * 3\n");
            }
        }
        m_app->HandleFrame(videoFrame->data(0), m_lastVideoFrameTimestampUs, videoFrame->width(), videoFrame->height());
        uint64_t ts_end = jvnn::CTool::GetTimeStapUs();
        nnDbg(NN_LOG, "frm: ts=%zu, cost time %zu us\n", m_lastVideoFrameTimestampUs, ts_end-ts_begin);

        return true; //< There were no errors while processing the video frame.
    }

    As the comment states, the method will be called per every frame. Let's assume the frame rate is 8 Frames per second. The method will be invoked 8 times per second.

    As I understand, you need one model per camera, meaning the model does not change from frame to frame. So, it can be loaded only once.

    Your model works correctly only if this condition is met.

    if (planeCount == 1 && lineSize0 == width * 3)

    Here is something, similar to what I'd recommend refactoring.

    DeviceAgent::DeviceAgent(const nx::sdk::IDeviceInfo* deviceInfo):
        // Call the DeviceAgent helper class constructor telling it to verbosely report to stderr.
        ConsumingDeviceAgent(deviceInfo, /*enableOutput*/ true)
    {
        nnDbg(NN_LOG, "Creating the app")
        m_app = new jvsp::AppSmokePhone(this);
        if (m_app) {
            nnDbg(NN_LOG, "Loading the model")
            m_app->LoadModel();
        }
    }

    Pay your attention, the model is loaded synchronously.

    bool DeviceAgent::pushUncompressedVideoFrame(const IUncompressedVideoFrame* videoFrame)
    {
        ++m_frameIndex;
        m_lastVideoFrameTimestampUs = videoFrame->timestampUs();

        uint64_t ts_begin = jvnn::CTool::GetTimeStapUs();
        if (!m_app) {
            return false
        }
               
        int planeCount = videoFrame->planeCount();
        int lineSize0 = videoFrame->lineSize(0);
        int width = videoFrame->width();
        int height = videoFrame->height();
        nnDbg(NN_LOG, "frame info: wh=%d*%d, planeCount=%d, lineSize(0)=%d\n", width, height, planeCount, lineSize0);
        if !(planeCount == 1 && lineSize0 == width * 3) {
            nnDbg(NN_ERR, "unsupport image format, planeCount != 1 || lineSize0 != width * 3\n");
            return false
        }    

        m_app->SetFrameInfo(width, height);
        m_app->HandleFrame(videoFrame->data(0), m_lastVideoFrameTimestampUs, videoFrame->width(), videoFrame->height());
        uint64_t ts_end = jvnn::CTool::GetTimeStapUs();
        nnDbg(NN_LOG, "frm: ts=%zu, cost time %zu us\n", m_lastVideoFrameTimestampUs, ts_end-ts_begin);

        return true; //< There were no errors while processing the video frame.
    }
    0
    Comment actions Permalink
  • Avatar
    zwq

    Hi

    According to your suggestion, modify the code as below, and vms restarts as the same

    DeviceAgent::DeviceAgent(const nx::sdk::IDeviceInfo* deviceInfo):
        // Call the DeviceAgent helper class constructor telling it to verbosely report to stderr.
        ConsumingDeviceAgent(deviceInfo, /*enableOutput*/ true)
    {
        if (!m_app) {
            m_app = new jvsp::AppSmokePhone(this);
            m_app->SetFrameInfo(1280, 720);
            m_app->LoadModel();
        }
    }

    bool DeviceAgent::pushUncompressedVideoFrame(const IUncompressedVideoFrame* videoFrame)
    {
        ++m_frameIndex;
        m_lastVideoFrameTimestampUs = videoFrame->timestampUs();

        uint64_t ts_begin = jvnn::CTool::GetTimeStapUs();
        if (m_app) {
            m_app->HandleFrame(videoFrame->data(0), m_lastVideoFrameTimestampUs, videoFrame->width(), videoFrame->height());
        }
        
        uint64_t ts_end = jvnn::CTool::GetTimeStapUs();
        nnDbg(NN_LOG, "frm: ts=%zu, cost time %zu us\n", m_lastVideoFrameTimestampUs, ts_end-ts_begin);

        return true; //< There were no errors while processing the video frame.
    }

    And new plugin is aviailable: https://drive.google.com/file/d/19qskQw5j8JrITn8CsDTPDd37SsdZLUHq/view?usp=share_link


    There is an core file in /opt/networkoptix/mediaserver/bin:
    you can open it with gdb, print the bt message as below:

    cd /opt/networkoptix/mediaserver/bin
    sudo chmod 777 core
    gdb mediaserver core

    (gdb) bt
    #0  __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
    #1  0x00007f92dd4b3859 in __GI_abort () at abort.c:79
    #2  0x00007f92dd954c20 in __gnu_cxx::__verbose_terminate_handler ()
        at /home/jenkins/conan-build-2/.conan/data/gcc-toolchain/10.2/_/_/build/f24d9d4a49445fd389b06d3f22addc2784700473/.build/x86_64-linux-gnu/src/gcc/libstdc++-v3/libsupc++/vterminate.cc:95
    #3  0x00007f92dd9533bd in __cxxabiv1::__terminate (handler=<optimized out>)
        at /home/jenkins/conan-build-2/.conan/data/gcc-toolchain/10.2/_/_/build/f24d9d4a49445fd389b06d3f22addc2784700473/.build/x86_64-linux-gnu/src/gcc/libstdc++-v3/libsupc++/eh_terminate.cc:48
    #4  0x00007f92dd9533ff in std::terminate ()
        at /home/jenkins/conan-build-2/.conan/data/gcc-toolchain/10.2/_/_/build/f24d9d4a49445fd389b06d3f22addc2784700473/.build/x86_64-linux-gnu/src/gcc/libstdc++-v3/libsupc++/eh_terminate.cc:58
    #5  0x00007f92dd9535e8 in __cxxabiv1::__cxa_throw (obj=0x7f92680154e0, tinfo=0x7f92bc7cd0c8, 
        dest=0x7f928d8fd9e0)
        at /home/jenkins/conan-build-2/.conan/data/gcc-toolchain/10.2/_/_/build/f24d9d4a49445fd389b06d3f22addc2784700473/.build/x86_64-linux-gnu/src/gcc/libstdc++-v3/libsupc++/eh_throw.cc:95
    #6  0x00007f928d85f9cb in ?? ()
       from /opt/networkoptix/mediaserver/bin/plugins/JVSmokePhone_analytics_plugin/libopenvino.so.2230
    #7  0x00007f928dffc65d in ov::Core::Core(std::__cxx11::basic_string<char, std::char_traits<char>, std::allocator<char> > const&) ()
       from /opt/networkoptix/mediaserver/bin/plugins/JVSmokePhone_analytics_plugin/libopenvino.so.2230

    I suspect the cause of the crash is an incompatible version of libstd++

    0
    Comment actions Permalink
  • Avatar
    Andrey Terentyev

    Hello,

    I suspect the cause of the crash is an incompatible version of libstd++

    That's might be the case. It's frequently faced issue.

    However, I can't reproduce the crash in my machine with the latest binaries you've shared.

    For detail, you could read the "Depending on libstdc++ on Linux" section in metadata_sdk/src/nx/sdk/dynamic_libraries.md.

    There are two ways.

    1.

    Note that the plugin must use the version of `libstdc++` compatible with the one of the Server with
    which the plugin is supposed to work.

    2.

    SOLUTION: For the plugin, use Clang together with its native `libc++` instead of `libstdc++`, and 
    link to `libc++` statically to make sure that the plugin will function properly even if the Server
    will start using `libc++` at some point in the future.

    In my machine, dependencies look like this

    You could try building your plugin with the same conan profile settings the Server was build to ensure library compatibility. You could find profiles in our repo on GitHub https://github.com/networkoptix/nx_open in "conan profiles".

    Make sure to check out the "vms_5.0" branch after cloning the repo.

     

     

    0
    Comment actions Permalink

Please sign in to leave a comment.

Didn't find what you were looking for?

New post