| Time |
Nick |
Message |
| 08:48 |
|
mantis1 joined #evergreen |
| 08:59 |
|
dguarrac joined #evergreen |
| 09:06 |
|
Dyrcona joined #evergreen |
| 09:50 |
Dyrcona |
@decide make bug on Lp or just move the test |
| 09:50 |
pinesol |
Dyrcona: go with just move the test |
| 09:51 |
Dyrcona |
A Friday is the wrong time to ask such a question, even though I'm pretty sure the answer will be "Yes." |
| 10:06 |
Dyrcona |
Think I'll open a Lp bug and let it sit for a few days, then take care of it if no one says or does anything. |
| 10:17 |
mantis1 |
trying to navigate the log process whenever an error happens when running the marc stream importer |
| 10:18 |
mantis1 |
I have looked around /openils/var/log but unsure which file it could be under |
| 10:18 |
mantis1 |
I think I tried open-ils.vandelay_stderr.log and wasn't able to find anything |
| 10:19 |
Dyrcona |
mantis1: osrfsys.log will have most of the backend calls. marc_stream_importer probably doesn't log its own errors. |
| 10:19 |
mantis1 |
Dyrcona++ I'll take a look |
| 10:19 |
Dyrcona |
Also, the stderr logs lack timestamps and are therefore nearly useless, IMHO. |
| 10:20 |
|
sandbergja joined #evergreen |
| 10:31 |
mantis1 |
I did notice that |
| 10:33 |
mantis1 |
is there a good phrase to grep? |
| 10:34 |
Dyrcona |
mantis1: Not sure, really. Do you know the time of the error? If I know the time, I'll often grep those log entries into a smaller file or at least just that one hour's worth. |
| 10:36 |
mantis1 |
hm looks like an error didn't really show |
| 10:36 |
Dyrcona |
It's almost always a pain finding the errors from utility scripts. |
| 10:36 |
mantis1 |
but it doesn't show a processing time |
| 10:37 |
Dyrcona |
Do you know the queue being used? You grep the log for thing related to the queue. |
| 10:37 |
mantis1 |
I know that the bibqueue flag when using this command needs to be an existing ID |
| 10:38 |
mantis1 |
I see a few errors when I think I tried it with original IDs and it says bib queue not found |
| 10:39 |
Dyrcona |
mantis1: Does the bibqueue exist in the database? |
| 10:55 |
mantis1 |
the one that I just ran does |
| 10:55 |
mantis1 |
no overlay |
| 10:56 |
csharp_ |
mantis1: in those cases I usually hack the script/library it's calling to add debug statements of my own to send to the logs alongside normal logging (e.g. $logger->info("CSHARP: current value of \$var is $var"), etc.) |
| 10:56 |
csharp_ |
always back up the original first, of course :-) |
| 10:58 |
csharp_ |
jeez - so much of coding is needing a very specific bit of information and spending hours figuring out how to get it efficiently |
| 10:59 |
Dyrcona |
Or even get it at all... |
| 11:00 |
Dyrcona |
Debuggers are nice, but debugging OpenSRF services is a real PITA. |
| 11:00 |
csharp_ |
"is the schema there?" - human: "\d schemaname <TAB><TAB>" script: "use DBI; create DBI object; create statement handle; code SQL; figure out how to get row data; figure out how to parse row data, etc" |
| 11:01 |
Dyrcona |
I used to really like Perl, but after nearly 13 years with Evergreen, I'd like to ditch the Perl and replace it with a sane language, and no, I don't mean Python.... :) |
| 11:02 |
csharp_ |
I guess AI will probably replace me and it won't matter |
| 11:02 |
* csharp_ |
is still in the "liking Perl" stage |
| 11:03 |
Dyrcona |
I think it's good for small stuff. Evergreen's backend isn't "small stuff." |
| 11:03 |
Dyrcona |
I feel the same way about Python for different syntactical reasons. |
| 11:03 |
csharp_ |
Dyrcona: C++? Rust? |
| 11:04 |
Dyrcona |
Yes. Either. |
| 11:04 |
Dyrcona |
At this point, probably Rust because writing safe C++ requires a good bit more experience. |
| 11:04 |
csharp_ |
and we're all getting Rust-y |
| 11:05 |
Dyrcona |
Rust can be slower in some applications, but in our case I don't think it will matter. |
| 11:05 |
|
Christineb joined #evergreen |
| 11:06 |
* Dyrcona |
goes back to creating race conditions with autorenewals and realizes that the race condition generator will have its own race conditions, but the more the merrier. |
| 11:06 |
Dyrcona |
Maybe I'll uncover some crazy new thing that only happens 1 in a million times. |
| 11:08 |
Dyrcona |
If I want to limit a json_query, I can just stick the limit on the end, right? I suppose I could check the find document... Nah, I'll just try it. |
| 11:11 |
|
redavis joined #evergreen |
| 11:16 |
Dyrcona |
Trouble is. I now have to wonder if my JSON query is correct. |
| 11:22 |
Dyrcona |
Helps to know which library actually did something... :) I was using org_units that had no data on my test system for today. |
| 11:22 |
Dyrcona |
My query works. I just need to refine it a little. |
| 11:25 |
Dyrcona |
I think I just want to hammer any state that isn't complete, invalid, or error. I might skip pending at first, too.Trouble will be knowing which org_unit to test soon enough to actually cause a race condition. |
| 11:27 |
mantis1 |
csharp: do you have any examples? I never had to put in original logs before |
| 11:27 |
Dyrcona |
I suppose I have time to pregame the 12:30 run and get the information ahead of time. |
| 11:28 |
Dyrcona |
mantis1: The marc_stream_importer has a --verbose command line option that actually does something. Maybe that will help? |
| 11:29 |
Dyrcona |
You can also look at it's code for examples of how to log things. |
| 11:29 |
Dyrcona |
its... Stupid English. |
| 11:39 |
mantis1 |
Dyrcona: can you stick that -v flag anywhere in the command? |
| 12:06 |
Dyrcona |
mantis1: should be able to. |
| 12:17 |
Dyrcona |
Oof. Looks like it is too late in the month to find many circulations. My data is out of date by 20+ days. |
| 12:19 |
csharp_ |
mantis1: if it's a Perl script/module with $logger already defined, you can just say $logger->info("the thing I want to log") |
| 12:19 |
csharp_ |
you can also do ->warn or ->error or ->debug but you don't want debug because you have to turn on *all* debugging to see it and it's not worth it |
| 12:20 |
csharp_ |
I usually use ->info |
| 12:20 |
csharp_ |
and if your logs are set up the way ours are, the output will go to osrfsys.HH.log |
| 12:21 |
csharp_ |
if you're watching in real time, make sure to put a marker in (e.g. MANTIS:) or something, then you can do tail -f osrfsys.HH.log | grep MANTIS |
| 12:21 |
csharp_ |
or "grep MANTIS osrfsys.HH.log | less" after the fact |
| 12:21 |
Dyrcona |
I think just using the --verbose option might help. |
| 12:22 |
csharp_ |
yeah, it all depends on what you're doing |
| 12:22 |
Dyrcona |
Also, of course nothing is due in two days, it's a Sunday on a holiday weekend.... My timing is bad. |
| 12:23 |
csharp_ |
I think a community development project worth considering would be to improve logging (remove unnecessary messages, add useful ones, make debug logs actually useful, etc.) |
| 12:23 |
Dyrcona |
I think my program will grab things due tomorrow, so I'll see that works out. |
| 12:23 |
Dyrcona |
csharp_++ I've been wanting to do something like that for years. I think we need some guidelines on coding and logging, like what to log, etc. |
| 12:23 |
csharp_ |
yes |
| 12:24 |
Dyrcona |
Standardized log messages would help ALOT! |
| 12:24 |
csharp_ |
and what not to log (e.g. debugging-while-coding lines that never get removed) |
| 12:25 |
csharp_ |
also, not ignoring Perl warning messages, as we have always done |
| 12:26 |
csharp_ |
see bug 2004420 |
| 12:26 |
pinesol |
Launchpad bug 2004420 in Evergreen "Let's quiet down the WARN logs!" [Low,New] https://launchpad.net/bugs/2004420 |
| 12:26 |
Dyrcona |
Speaking of debugging: I found out recently that you can use gdb with the Enbugger module to debug Perl. I've not tried it, but I think it might be more convenient than using the Perl debugger. |
| 12:26 |
* csharp_ |
runs off to tell smayo, who really wants a Perl debugger |
| 12:35 |
mantis1 |
I see a bunch of these with a recent run |
| 12:35 |
mantis1 |
No request was received in 6 seconds, exiting stateful session |
| 12:36 |
Dyrcona |
You can debug OpenSRF with the perl debugger, but it's a pain: https://docs.google.com/document/d/1sh2foeH-00yoz4K3FZLWlkI1W2-6ekRhWg1CvY4FRss/edit?usp=sharing |
| 12:38 |
Dyrcona |
Something is timing out, usually means it's taking too long in the database. You can try to find out what by using the number between colons after the message type inside the brackets. |
| 12:38 |
Dyrcona |
[2025-05-23 12:30:35] open-ils.trigger [INFO:4664:Transport.pm:163:] Message processing duration: 19.635 |
| 12:38 |
mantis1 |
Dyrcona++ |
| 12:40 |
Dyrcona |
In that example, I'd use 4664 to trace the process. The problem is that the timed out process is usually a different one. You might be able to figure that one out by looking for the most recent message of something like "sending data to " or something saying it's making an open-ils service call. |
| 12:41 |
Dyrcona |
On my race condition issue, I'm also trying to race against the a/t runner when it's only doing 30 or so events. It finishes faster than I can get started. |
| 12:42 |
mantis1 |
ok I have a different error after running a different file with a different bibqueue |
| 12:42 |
mantis1 |
import_error=general.unknown error_detail=DATABASE_UPDATE_FAILED : The attempt to write to the DB failed purpose=import attributes= matches=ARRAY(0x55d4a010eae0) import_items= quality= isnew= ischanged= isdeleted= |
| 12:43 |
Dyrcona |
If your postgresql is logging errors, you can try the database log. Sometimes you can get more information int opensrf log, but I'd start with the postgres logs. |
| 12:51 |
|
smayo joined #evergreen |
| 13:52 |
csharp_ |
@decide your postgresql or my postgresql |
| 13:52 |
pinesol |
csharp_: go with my postgresql |
| 13:52 |
csharp_ |
tu postgres es mi postgres |
| 14:37 |
Dyrcona |
mi postgres es su postgres |
| 14:38 |
Dyrcona |
Looks like I'll have to wait until Tuesday to test my hypothesis with my race condition program. I'm not getting enough events today for a/t to run very long. |
| 14:40 |
Dyrcona |
oh. my. Looks like I need to refresh my data from production. With my current out of date data, I'll have even fewer transactions next Tuesday.... |
| 14:40 |
Dyrcona |
Think I'll go ahead and grab a recent dump. |
| 15:05 |
Dyrcona |
I think I'll modify my hack to trap the errors and through them. After looking at Event.pm it appears that throwing a string would be more appropriate. |
| 15:16 |
|
mantis1 left #evergreen |
| 15:19 |
Dyrcona |
through them? I think I meant "throw them." I'm also using die() now instead of throw because use of the Error module is discouraged. Seems like every 10th Perl module's use is discouraged these days. |
| 15:32 |
Dyrcona |
Y'know. I should log the event state when I mess with the circulation so I can better see what happens. |
| 16:52 |
Dyrcona |
Have a nice weekend, everyone! |
