elad-bar / ha-hpprinter

HP Printer Integration
89 stars 25 forks source link

Error "/DevMgmt/ProductUsageDyn.xml" every 10 sec #170

Open BennyOtt opened 1 week ago

BennyOtt commented 1 week ago

Hi,

Interestingly, the log is currently running relatively frequently, because every 10 seconds my printer generates /DevMgmt/ProductUsageDyn.xml, which has no content. 2.0.3 is installed

It is an HP Officejet Pro 8210 that does not have a scanner.

`2024-06-20 21:17:15.045 ERROR (MainThread) [custom_components.hpprinter.managers.rest_api] Failed to get /DevMgmt/ProductUsageDyn.xml, Error: no element found: line 1, column 0, Line: 403, Time: 0.040s

2024-06-20 21:17:25.045 ERROR (MainThread) [custom_components.hpprinter.managers.rest_api] Failed to get /DevMgmt/ProductUsageDyn.xml, Error: no element found: line 1, column 0, Line: 403, Time: 0.040s

2024-06-20 21:17:35.044 ERROR (MainThread) [custom_components.hpprinter.managers.rest_api] Failed to get /DevMgmt/ProductUsageDyn.xml, Error: no element found: line 1, column 0, Line: 403, Time: 0.039s`
elad-bar commented 1 week ago

Pls provide debug log level logs and diagnostics files

igorsantos07 commented 1 week ago

Here it is :)

home-assistant_hpprinter_2024-06-21T01-30-39.310Z.log

elad-bar commented 1 week ago

something is very wrong with your system / network, pls read the logs and start fixing it one by one, on top of it, requests to the printer takes more 5 seconds, it's not an issue of the intergation

igorsantos07 commented 1 week ago

So it's not an issue when your code causes thousands upon thousands of errors "failed to get xyz", and then you me for other unrelated things in my HA log? 😂 That's the right way to do software development, definitely...

elad-bar commented 1 week ago

since you are the BEST software developer across the universe i probably should teach you basic principle of development like:

now, if one of your users has an issue with his/her environment, they should fix it before contacting you, unless your code created that problem...

is that the case? no, so as you would have done because you are (again) THE BEST developer, i suggested to fix the issues within your environment first.

if you don't want to change anything in your environment and fix the issues (templates that are running with lots of issues in them every 3ms and messing up with your system), and would like to ignore logs of specific intergation / component in HA, I suggest to read the manual of HA and address it in Logger component, since you now when to focus on the most important issues, error in log because you have an issue accessing to device you integrated to every 10 seconds, rather fix and issue that filling up your logs every 3ms...

before complainig on standards of others, start with yourself.

IF YOU FIND THAT POST BIT OFFENSIVE, THE NEXT TIME, BE MORE REPECTFUL TO OTHERS!

elad-bar commented 1 week ago

@BennyOtt i was under the wrongly impression logs provided by you, please provide me logs and i will be able to assist with your issue.

elad-bar commented 1 week ago

@igorsantos07 btw, next time when you are posting logs, read the issue and make sure it's the same as yours before ridding on it

error reported here is about failure to process data while logs you have shared are for timeouts (again, issue accessing from you system to the printer).

BennyOtt commented 1 week ago

@BennyOtt i was under the wrongly impression logs provided by you, please provide me logs and i will be able to assist with your issue.

The other problem seems to have been resolved, for whatever reason my printer didn't display it at the time. It was also interesting that at some point the printer was no longer accessible and all connections were rejected.

What I'm surprised about, though, is why it's making so many requests. A normal ping from HA reaches the printer in about 1 ms. Calling up the XML accordingly takes 1-2 seconds even on my computer.

home-assistant_hpprinter_2024-06-21T12-10-44.032Z.log

elad-bar commented 1 week ago
calls explained below Endpoint Data Interval Times a day
/DevMgmt/ProductConfigDyn.xml Main device details 52w 0.0027
/DevMgmt/ProductStatusDyn.xml Device status 10s 8,640
/DevMgmt/ConsumableConfigDyn.xml Consumables 5m 288
/DevMgmt/ProductUsageDyn.xml Consumables, Printer, Scanner, Copier, Fax 5m 288
/ePrint/ePrintConfigDyn.xml ePrint 5m 288
/IoMgmt/Adapters Network Adapters 5m 288
/DevMgmt/NetAppsSecureDyn.xml Wifi 5m 288

only call that running every 10 seconds should be regarding device status, in all releases since added device status (v1) up until v2.0.2 - it called all endpoints all the time, i reduced amount of calls, status remains... I can add a feature to update the interval for each of the endpoints and allow users to control it, but that will take time.

i see lots of timouts for you device, is it offline? reason i'm asking, all endpoints returns timeout (not 404 or any other issue).

in v2.0.4, i have added better handling to online / offline modes of the printer, maybe it will reduce the amount of request additionally when the printer is offline (depends on the answer above)

which version are you using?

thanks

BennyOtt commented 1 week ago

2.0.3 and printer is online or accessible now with the update to 2.0.4 it looks much better and there are no more timeouts.

elad-bar commented 1 week ago

Great, leaving it open for follow up in yhe upcoming few days

igorsantos07 commented 1 week ago

@elad-bar sorry if I didn't know any better, but you can't say I didn't "read the issue". The messages on my logs are the SAME as in the originating issue. If it's not caused by the same issue, then I am not able to know - if I knew, I would not post the logs but a solution instead :shrug:

But indeed, sorry for not making it clear I wasn't the OP. That was indeed a mistake I made, since I was pretty sure the same error messages would mean the same error - I mean, why would I think the opposite?

About the rest of your complaints... I still can't think how you were respectful to me when you shut the issue down in the first place, complaining about unrelated things in my logs, in such an ugly way. The main issue there is that, actually, logs about the integration include unrelated stuff as well. I guess there could be a reason for that, but that's still not a reason for you to complain about whatever else is going on in my installation instead of focusing on the reported problem. Not to mention, you could just used good'old "find in file" to look for the hppprinter messages on the logfile.

Lastly... even IF the reported issue was caused by silly things like broken templates, it would make no sense at all for the integration to break because of that. Otherwise, as you yourself mentioned:

  1. protect your own environment: you should protect your integration from getting in a broken state because of other integrations or "broken templates"
  2. write logs. Readable logs, not "failed to get XML on line 123". If that's caused by a connection issue, write defensive code to say "can't connect to printer" instead of spitting an XML error. Then, your users will be able to understand what's going on, instead of trying to haplessly post logs in look for help.

Bonus: besides the latest versions that indeed stopped with the constant logging of errors, I noticed I forgot to trash the integration and create it again when updated to v2. It could be useful if, next time you're doing breaking changes, if the integration left a "repair" notice on HA stating stuff like "HPPrinter integration had to re-do everything, and it's now in a broken state. Re-create it from scratch."

elad-bar commented 1 week ago

I like the approch of attack and then get offensive, that doesn't work... I simply wrote that you have many other issues and you should fix them first, why? 5mb file that is not matching to the request for me to debug it, debug log level for the integration was not there, what was there? 40% of the log file (out of 50k lines) was about errors that took place every 1-3msec related to template you have wrote in your system, relevancy to the issue - none, Asked for debug log level, so I will be able to understand the issue, btw, as developer you should know that there are levels of logs that in each of them you are explaining what happen, so in case you got error which is not clear, you will be able to understand the context and fix it, But here you are for the 2nd time, try to teach me how to code, If you know it better then me, you can suggest a PR and not just complain how bad my code is, I spend many hour to provide that integration as well as 7 others in my own personal time, you can respect it, you can respect also the fact that without the details which for you as developer should be under the common sense, will not assist to solve it, So if I get a log not matching to what i have asked, I see that there are many other issues, I will make an assumption that in most cases will be based on what I know - if your system has many issues that happens in parallel to issues with the printer that leads for long duration extracting the data, it is either:

  1. Your system has an issue of lack of threads to make a call to the printer
  2. You have network issue that even your printer doesn't respond fast enough

If you find my assumption wrong, please provide what i asked for me to debug., Again, I have 7 integrations to maintain on top of day to day job and personal life, you find it offensive that I closed the issue, I find it waste of time to try understand something that is not working in an unstable environment (following the assumptions above) and lack of logs as I asked for to assist you, not to introduce new challenges to your life, If as result of that you are attacking someone that don't owe you anything, it will not work for you

As I wrote to the issue reporter, i need debug logs to understand what happen, you would like to provide them great, up to you

igorsantos07 commented 1 week ago

So, repeating myself - and not pointing the finger towards you -, I wonder why the heck when you "enable debug logging" on a specific integration's page, HA creates a log with absolutely everything it had logged in the meantime.

I mean, you're right on complaining about the log I sent being filled with irrelevant stuff. But it's not my fault either, and I guess you didn't know HA would do that kind of thing. At least I didn't :shrug:

I guess it kinda makes sense, in cases where an issue might be related to other stuff outside the integration... But it was indeed very unfortunate when I just got tired of some templating on cards and left them "working as is", not even realizing they were causing tons of errors on my logs. The most frequent one and always at the top was, exactly, the one entitling this issue.

I should point out that, while I don't recall the exact steps I took two days ago, given the file I uploaded had the integration name on it, most probably it came from the enable debug logging option and, thus, should include the information you needed - even though it was drowned by other irrelevant errors.

But yeah, I guess we both were having bad days and it was a communication issue? Peace? :upside_down_face:

elad-bar commented 1 week ago

bad day it was, sorry for my part in making it, new day new start :)

enable debug logging is adding configuration to log in debug level, but it will also bring the rest of the logs, best way to handle it when you would like to post logs for specific component / integration is to isolate as much as possible "noise", in configuration yaml:

logger:
  default: warning
  logs:
    custom_components.hpprinter: debug

what i'm missing in logs is the transition between status of http requests, that will explain why it's not working (if the issue caused by a bug in the integration)