2021-09-22, 01:14 PM
Hi,
I have spotted some scheduled recordings are failing with the message "Recording service not running at recording time"
Finally I got round to looking into it, and the nrecord log is saying this:
2021-09-22 00:57:03.015 [DEBUG][177] Got request [127.0.0.1]: /service (session.login)
2021-09-22 00:57:03.015 [DEBUG][177] method=session.login
2021-09-22 00:57:03.015 [DEBUG][177] parameters:
2021-09-22 00:57:03.015 [DEBUG][177] method: session.login
2021-09-22 00:57:03.015 [DEBUG][177] sid: 220b58be7f324846a062867d6a34d84d
2021-09-22 00:57:03.015 [DEBUG][177] md5: 4A8FA0A74DB18C39C5409A9C5A14F8B5
2021-09-22 00:57:03.015 [DEBUG][177] client_ip: 127.0.0.1
2021-09-22 00:57:03.015 [DEBUG][177] host_callback: 127.0.0.1:8866
2021-09-22 00:57:03.015 [INFO][177] LoginSession(sid = 220b58be7f324846a062867d6a34d84d)
2021-09-22 00:57:03.016 [DEBUG][177] [MYABfGMGA4Hg3PGK0ZX4TiMEnge0Ap8QzXJHLktp7ylBJrjGRw2OJod6pejtO9USpkVyhDmvt6TNDlRNqVKQYAZA3yYNZ9BWvGLPfWdJY8OxAcyEBgvvrEHVPn5m9hAsr1afk+NitxFp173JhHOlGLBqxyi7OMvCt76N7oDCs6cu9c6PnzRIYUuw6jytyUKcq/lWRlt2o/3nBkrWS7mSx8M9ZFQq84d3BrL5wQPuATG8PMfXEtmO1/0QrsszvewxPGTEZMcbr8qfzyjtKV3Qgu6Jgf1tO13kR0Soi/kZqdCAmIGL518cjrU+OWsda+f4MaiXeNQkzI+gutiMZXHXaLsSz/AVk5zFztmYyO5BK/OL3wtxeyKj5Bwp4zFQfhCF1oNRGUKWeUrVLGvvZqZuaJXEkCU/RO6UDrNpspBQKPb7ocR1fjCgE0b4q+fTcqSQOiO3JdfjpBo49bGhOuxqbA==]
2021-09-22 00:57:03.016 [DEBUG][177] [mWZrcuS26M9gtDY4HJ+/m7Q/BtWgXf0qHY6pbQ01Plw45gNckkVMefc9V67xtOAaPRHX6fMRdVjQw2vmU42sg0uQ54SR7TSsIdCVhPH8f2xqt/JFPpaO/1jw+BSfLyWW0DuUI00qcaLPEi9krsFIm91ab81NFsg+Du2yNzWGyoViDEu6Id2npPRh8zVRplBjuYmEHoP+SYDzOArh+m0C9F7BtWw7zRSJyQMnGKBK/ydzZ3DG6LXcgMByhTvEHQUzCEp7jm4i601IdKDkYxkCO8MN21UWUpK2ppbIJREp0vWac/GDsuLGMsFnXuyqP3vcqou5h+s932IR5Vwjry4DYE7eEhiiDdN0Qf1a1W5UR/yNQ7PaLvr6sbCOPJUJZ3adLT4uHnxNbVGCNWpyL/lmX3Q57zCec+3o0HnETAwbPbk=]
2021-09-22 00:57:03.016 [DEBUG][177] [cEmHiz3zmAZQYIYhVj4ZCO5fsdejNzDYil+7MvNdWeWGpse9wZYugXiOLAwev5Q6XrJZoILJzfTWYfJ++Wl6idw7M1Z9QIXwM9/Hm+b8QfiCHsx+wZDYCE0GeX70vQL+n+2TWbRkmolSt6O6g+Cmn4ORdZkM0LQZrPgITgEqr4DKSsP6O1wWpDreTMXJCW7+b/IjPrEjY+qL+gdgWm/xil8PVZkY3vzJGaX94JYrwaGE0+WnLmXwol53PClBG7d11uot1w4DdDcXScmsm1a5ySK9wgjY7TZVcnJD9Mq1JQ4EGERr0XZsDB8POsgbcAs3ST7yqQ1BKHysVBcXffdgbcrRTRmEA0oNlexxuNe2nTqrifaxUBOAz8aqJVY0m1Br9++5I4BolOKCHoQOwHi0NWK2aTXoyGgCDjFNJEfIDVQ=]
2021-09-22 00:57:03.016 [DEBUG][177] <?xml version="1.0" encoding="utf-8" ?>
<rsp stat="fail">
<err code="1" msg="Login Failed" />
</rsp>
2021-09-22 00:57:03.023 [DEBUG][174] > [1] Unable to login
2021-09-22 00:57:03.023 [DEBUG][34] > Unable was unexpected at this time.
2021-09-22 00:57:03.146 [DEBUG][170] found match
2021-09-22 00:57:03.231 [DEBUG][173] Done fanart.tv lookup
2021-09-22 00:57:03.497 [DEBUG][172] got season info
2021-09-22 01:03:00.180 [DEBUG][14] Stopping recording (12524 on 101). Past end time of recording. 3
2021-09-22 01:03:00.286 [DEBUG][14] http://localhost:64472/stream/stop?handle=3
2021-09-22 01:03:00.297 [DEBUG][14] StoreMetaData@2
2021-09-22 01:03:00.312 [DEBUG][14] StoreMetaData@exit
2021-09-22 01:03:00.313 [DEBUG][14] No C:\Users\Public\NPVR-data\scripts\PostProcessing.bat
2021-09-22 01:33:10.018 [DEBUG][144] [Suspend]
2021-09-22 01:33:10.018 [DEBUG][144] OnSleep...
2021-09-22 01:33:10.018 [DEBUG][144] stopping device process
2021-09-22 06:00:19.500 [DEBUG][14] Marking recording (12547) as 'Recording service not running at recording time'
I am running NPVR on a Windows Server Essentials setup, with LightsOut installed, which will hibernate the server if there are no clients connected or no activity. I configured the ParallelProcessing batch file to create a text file while recording is taking place, and LightsOut to monitor the text file. Once the recording is complete, the text file is deleted, and the server is put back into hibernation.
Now NScriptHelper.dll is having issues, this is not working. Has anyone else seen this issue before with the script helper? I have attached the other relevant logs to the post.
Thanks
I have spotted some scheduled recordings are failing with the message "Recording service not running at recording time"
Finally I got round to looking into it, and the nrecord log is saying this:
2021-09-22 00:57:03.015 [DEBUG][177] Got request [127.0.0.1]: /service (session.login)
2021-09-22 00:57:03.015 [DEBUG][177] method=session.login
2021-09-22 00:57:03.015 [DEBUG][177] parameters:
2021-09-22 00:57:03.015 [DEBUG][177] method: session.login
2021-09-22 00:57:03.015 [DEBUG][177] sid: 220b58be7f324846a062867d6a34d84d
2021-09-22 00:57:03.015 [DEBUG][177] md5: 4A8FA0A74DB18C39C5409A9C5A14F8B5
2021-09-22 00:57:03.015 [DEBUG][177] client_ip: 127.0.0.1
2021-09-22 00:57:03.015 [DEBUG][177] host_callback: 127.0.0.1:8866
2021-09-22 00:57:03.015 [INFO][177] LoginSession(sid = 220b58be7f324846a062867d6a34d84d)
2021-09-22 00:57:03.016 [DEBUG][177] [MYABfGMGA4Hg3PGK0ZX4TiMEnge0Ap8QzXJHLktp7ylBJrjGRw2OJod6pejtO9USpkVyhDmvt6TNDlRNqVKQYAZA3yYNZ9BWvGLPfWdJY8OxAcyEBgvvrEHVPn5m9hAsr1afk+NitxFp173JhHOlGLBqxyi7OMvCt76N7oDCs6cu9c6PnzRIYUuw6jytyUKcq/lWRlt2o/3nBkrWS7mSx8M9ZFQq84d3BrL5wQPuATG8PMfXEtmO1/0QrsszvewxPGTEZMcbr8qfzyjtKV3Qgu6Jgf1tO13kR0Soi/kZqdCAmIGL518cjrU+OWsda+f4MaiXeNQkzI+gutiMZXHXaLsSz/AVk5zFztmYyO5BK/OL3wtxeyKj5Bwp4zFQfhCF1oNRGUKWeUrVLGvvZqZuaJXEkCU/RO6UDrNpspBQKPb7ocR1fjCgE0b4q+fTcqSQOiO3JdfjpBo49bGhOuxqbA==]
2021-09-22 00:57:03.016 [DEBUG][177] [mWZrcuS26M9gtDY4HJ+/m7Q/BtWgXf0qHY6pbQ01Plw45gNckkVMefc9V67xtOAaPRHX6fMRdVjQw2vmU42sg0uQ54SR7TSsIdCVhPH8f2xqt/JFPpaO/1jw+BSfLyWW0DuUI00qcaLPEi9krsFIm91ab81NFsg+Du2yNzWGyoViDEu6Id2npPRh8zVRplBjuYmEHoP+SYDzOArh+m0C9F7BtWw7zRSJyQMnGKBK/ydzZ3DG6LXcgMByhTvEHQUzCEp7jm4i601IdKDkYxkCO8MN21UWUpK2ppbIJREp0vWac/GDsuLGMsFnXuyqP3vcqou5h+s932IR5Vwjry4DYE7eEhiiDdN0Qf1a1W5UR/yNQ7PaLvr6sbCOPJUJZ3adLT4uHnxNbVGCNWpyL/lmX3Q57zCec+3o0HnETAwbPbk=]
2021-09-22 00:57:03.016 [DEBUG][177] [cEmHiz3zmAZQYIYhVj4ZCO5fsdejNzDYil+7MvNdWeWGpse9wZYugXiOLAwev5Q6XrJZoILJzfTWYfJ++Wl6idw7M1Z9QIXwM9/Hm+b8QfiCHsx+wZDYCE0GeX70vQL+n+2TWbRkmolSt6O6g+Cmn4ORdZkM0LQZrPgITgEqr4DKSsP6O1wWpDreTMXJCW7+b/IjPrEjY+qL+gdgWm/xil8PVZkY3vzJGaX94JYrwaGE0+WnLmXwol53PClBG7d11uot1w4DdDcXScmsm1a5ySK9wgjY7TZVcnJD9Mq1JQ4EGERr0XZsDB8POsgbcAs3ST7yqQ1BKHysVBcXffdgbcrRTRmEA0oNlexxuNe2nTqrifaxUBOAz8aqJVY0m1Br9++5I4BolOKCHoQOwHi0NWK2aTXoyGgCDjFNJEfIDVQ=]
2021-09-22 00:57:03.016 [DEBUG][177] <?xml version="1.0" encoding="utf-8" ?>
<rsp stat="fail">
<err code="1" msg="Login Failed" />
</rsp>
2021-09-22 00:57:03.023 [DEBUG][174] > [1] Unable to login
2021-09-22 00:57:03.023 [DEBUG][34] > Unable was unexpected at this time.
2021-09-22 00:57:03.146 [DEBUG][170] found match
2021-09-22 00:57:03.231 [DEBUG][173] Done fanart.tv lookup
2021-09-22 00:57:03.497 [DEBUG][172] got season info
2021-09-22 01:03:00.180 [DEBUG][14] Stopping recording (12524 on 101). Past end time of recording. 3
2021-09-22 01:03:00.286 [DEBUG][14] http://localhost:64472/stream/stop?handle=3
2021-09-22 01:03:00.297 [DEBUG][14] StoreMetaData@2
2021-09-22 01:03:00.312 [DEBUG][14] StoreMetaData@exit
2021-09-22 01:03:00.313 [DEBUG][14] No C:\Users\Public\NPVR-data\scripts\PostProcessing.bat
2021-09-22 01:33:10.018 [DEBUG][144] [Suspend]
2021-09-22 01:33:10.018 [DEBUG][144] OnSleep...
2021-09-22 01:33:10.018 [DEBUG][144] stopping device process
2021-09-22 06:00:19.500 [DEBUG][14] Marking recording (12547) as 'Recording service not running at recording time'
I am running NPVR on a Windows Server Essentials setup, with LightsOut installed, which will hibernate the server if there are no clients connected or no activity. I configured the ParallelProcessing batch file to create a text file while recording is taking place, and LightsOut to monitor the text file. Once the recording is complete, the text file is deleted, and the server is put back into hibernation.
Now NScriptHelper.dll is having issues, this is not working. Has anyone else seen this issue before with the script helper? I have attached the other relevant logs to the post.
Thanks