| Posted | Nick | Remark | |
|---|---|---|---|
| #openstack-nova - 2017-05-03 | |||
| 16:40:00 | mriedem | this is a full dump of the instance | |
| 16:40:02 | mriedem | and all of it's fields | |
| 16:40:05 | dansmith | ah | |
| 16:40:07 | sdague | right | |
| 16:40:08 | mriedem | and the display_name in one test is unicode | |
| 16:40:17 | sdague | which is when it all blows up | |
| 16:40:25 | mriedem | not using the instance=instance kwarg | |
| 16:40:26 | dansmith | I dunno, I thought someone did a few utf tweaks when they py3-ified it, but I dunno | |
| 16:40:26 | melwitt | the __repr__ returns a bytes string in PY2 to be native with the rest | |
| 16:41:50 | melwitt | and converting it to unicode before logging it makes it work. it's just I had to repr(instance) and then six.text_type(instance_repr, 'utf-8') | |
| 16:47:01 | clarkb | this would be a general issue for things like https://git.openstack.org/cgit/openstack/oslo.log/tree/oslo_log/handlers.py#n56 too right? | |
| 16:47:12 | clarkb | eg its not specific to the journald handler we juts happen to be using it in testing so catch it | |
| 16:49:13 | sdague | clarkb: it blows up on the format() | |
| 16:49:16 | sdague | not on the send | |
| 16:49:27 | sdague | that solution would be too late | |
| 16:49:43 | sdague | there would be an exception at L73 | |
| 16:49:45 | clarkb | right I'm saying the syslog handler does the format in emit too | |
| 16:49:58 | clarkb | so the bug is also in that handler | |
| 16:51:06 | sdague | clarkb: ok, so the solution is? | |
| 16:52:10 | clarkb | I think what melwitt described, do your formatting outside of the logger (which has the downside of possibly being unnecessary depending on log level)? | |
| 16:53:13 | clarkb | or possibly you can manipulate locks within logging? | |
| 16:53:27 | clarkb | that seems fragile | |
| 16:53:40 | sdague | clarkb: ?? the locking issue is different | |
| 16:54:06 | sdague | so, if I dive down the FileHandler -> StreamHandler path | |
| 16:54:08 | clarkb | sdague: oh I understood it as oyu need db lock to format the instance repr and you need logging lock to use the logger | |
| 16:54:25 | sdague | clarkb: no you have mixed up 2 different issues | |
| 16:54:29 | clarkb | ah sorry | |
| 16:54:46 | sdague | StreamHandler does the same - msg = self.format(record) | |
| 16:55:14 | abhishek | melwitt: just a reminder, https://review.openstack.org/#/c/460305/ | |
| 16:55:30 | melwitt | sdague: yeah, I'm trying to figure out what is different. does StreamHandler use the same formatter as OSJournalHandler? I don't get what is different here | |
| 16:55:40 | sdague | melwitt: yep | |
| 16:55:48 | sdague | melwitt: so these things have definitely been around before | |
| 16:56:10 | sdague | I went diving after one of these before | |
| 16:56:26 | sdague | and there are as many successes as fails on mriedem's issue | |
| 16:56:32 | clarkb | the format issue is purely a unicode problem? | |
| 16:56:40 | sdague | clarkb: that is my believe | |
| 16:56:44 | sdague | belief | |
| 16:56:58 | melwitt | sdague: oh, so something else about the change to the journal logger has just made this happen or timed in a way that we see it in gate failures now? | |
| 16:57:04 | sdague | I'm actually starting to think it's a red herring | |
| 16:57:27 | sdague | melwitt: I expect the deadlocking that was causing dansmith's bugs is actually the issue | |
| 16:58:23 | melwitt | sdague: yeah, I think you're right | |
| 16:58:30 | sdague | https://review.openstack.org/#/c/462163/2/functions will fix that | |
| 16:58:56 | sdague | melwitt: that being said, I still think there is a general utf8 bug in ovo repr that would be good to fix :) | |
| 16:59:13 | sdague | at least adding utf8 tests to ovo | |
| 16:59:20 | cfriesen | where does the service version get determined? I don't see it in the Service object. | |
| 17:00:48 | clarkb | sdague: so with that change in place journald will still get the service logs out of stdout? we just won't use the native writer right? | |
| 17:00:57 | sdague | clarkb: correct | |
| 17:01:12 | sdague | systemd will still injest them | |
| 17:01:44 | sdague | they just miss out on the native annotations, which include things like code line, correct process_id, and extras | |
| 17:01:47 | melwitt | sdague: yeah ... I'll look at that. it's not straightforward to me bc the __repr__ intentionally converts to bytes (opposite of what we want for the logging) and it seems to work fine outputting to stdout for example, so I don't yet understand what should be done there | |
| 17:02:27 | sdague | melwitt: yeh, I'm not sure I do either. But it also doesn't look like any of the ovo tests have utf8 strings in them | |
| 17:02:33 | sdague | that would at least be a start | |
| 17:04:33 | melwitt | sdague: ack. will do | |
| 17:07:35 | mriedem | cfriesen: nova.service._update_service_ref | |
| 17:08:56 | mriedem | cfriesen: and __init__ of the Service object | |
| 17:08:58 | mriedem | when creating a new one | |
| 17:09:02 | mriedem | self.version = SERVICE_VERSION | |
| 17:10:17 | sdague | mriedem: what things do you want in syslog.txt ? | |
| 17:24:13 | mriedem | sdague: not the openstack service logs | |
| 17:25:57 | sdague | mriedem: sure, but we have to build back up which things you want in there | |
| 17:28:03 | sdague | https://review.openstack.org/#/c/462231/ | |
| 17:29:10 | mriedem | sdague: i don't know honestly, syslog was my place to go look for native process things on the system, like libvirt, mysql, tgtd, kernel stuff, etc | |
| 17:29:16 | mriedem | i'd use the libvirt logs for libvirt debug info, | |
| 17:29:22 | mriedem | and the openstack service logs for openstack service things | |
| 17:29:55 | mriedem | the journal gz files are less useful to me since i can't use them in the browser, and have to pull them down | |
| 17:30:32 | sdague | mriedem: right, well, we're in systemd world, everything is in the journal | |
| 17:30:46 | sdague | and the export has to be based on inclusion, not exclusion | |
| 17:31:12 | sdague | so going to start with kernel / sudo | |
| 17:31:20 | sdague | and if you want other topics please propose | |
| 17:32:28 | openstackgerrit | Gábor Antal proposed openstack/nova master: Transform aggregate.remove_host notification https://review.openstack.org/396211 | |
| 17:33:27 | mriedem | sdague: that's likely a fine start, and if i really need to debug anything that i'd normally find in syslog, or look in syslog for, i'll have to pull the journal down | |
| 17:33:45 | mriedem | sdague: that means we might lose some things that we were indexing from syslog into logstash before, | |
| 17:33:49 | mriedem | but that's probably a small set, idk | |
| 17:33:54 | mriedem | libvirt things for sure though... | |
| 17:34:14 | sdague | mriedem: it does, so if there are important things, I'd suggest just adding topics | |
| 17:34:43 | sdague | mriedem: there is a reason I'm asking you what topics you want, because I expect you are one of the top users :) | |
| 17:34:55 | sdague | so I'm totally good with mriedems private label topics list | |
| 17:35:02 | clarkb | dnsmasq | |
| 17:35:13 | clarkb | thats been useful to debug dhcp things int he past | |
| 17:35:38 | sdague | clarkb: it has, though usually not with a spot check | |
| 17:35:52 | mriedem | i dumped the current open e-r queries that rely on syslog in the patch | |
| 17:35:54 | sdague | it will still be in the journal dump | |
| 17:36:02 | mriedem | i haven't dug into what they are looking for though, because i'm lunching | |
| 17:36:07 | sdague | mriedem: ok | |
| 17:36:14 | sdague | speaking of, I need to do that | |
| 17:36:26 | sdague | then will be intermittent for the rest of the day | |
| 17:37:02 | sdague | I fast approved the disable on use_journal - https://review.openstack.org/#/c/462163/ - so hopefully in a couple of hours that will be in | |
| 17:38:25 | mriedem | cool | |
| 17:39:25 | mriedem | cfriesen: are you going to be at the summit? | |
| 17:39:46 | mriedem | because there is a session where all of your questions can be answered! | |
| 17:40:06 | mriedem | unless they have something to do with numa and pci, then we'll be asking you for the answeres | |
| 17:40:08 | mriedem | *answers | |
| 17:51:01 | mriedem | jaypipes: i had no idea wookiee had 2 es | |
| 17:51:36 | jaypipes | mriedem: you're welcome :) | |
| 17:51:41 | jaypipes | TIL... | |
| 17:51:42 | mriedem | i actually like this format | |
| 17:51:51 | mriedem | puts mine to shame | |
| 17:51:54 | mriedem | damn you | |
| 17:53:34 | mriedem | rxtx factors, ha | |
| 17:53:49 | mriedem | didn't i see sfinucan trying to remove all of that? | |