This question is answered. Helpful answers available: 1. Correct answers available: 1.


Permlink Replies: 59 - Pages: 4 [ 1 2 3 4 | Next ] - Last Post: 21 Oct 22, 19:26 Last Post By: MarkusD
MarkusD

Posts: 761
Registered: 13-Apr-2006
Time stamp in the console
Posted: 4 Oct 22, 20:48
 
  Click to reply to this thread Reply
Hi,

I'm still surprised that the console with the log lacks vital information which makes it difficult to read it. So, what is missing? A time stamp. Without it, it is impossible to analyse which step has a potential to speed things up. In our own applications time stamps are vital. They look like this:



  • So we have a unique line number, which makes it easy when you communicate with a colleague: „Hey Joe, just look in line 00123, that looks strange“;
  • We have a date;
  • We have a time;
  • And the time includes of course also milliseconds;

I don't understand how team Sweden, Laza, Jeff and Rob are working without this vital info.

I really would like to see time stamps in the log.

Of course, I am very curious as to why a time stamp is not important. :-)

Thanks, Markus
RobM

Posts: 3,947
Registered: 4-Aug-2006
Re: Time stamp in the console
Posted: 4 Oct 22, 21:25   in response to: MarkusD in response to: MarkusD
 
  Click to reply to this thread Reply
What do you want a timestamp for, everything, making an album, uploading it, running a tool?

Most of us only look at the console logs when developing things or debugging a core problem.
I'm more interested in where an issue is than what time it happened.

If you set the logging level, in preferences, to FINER you will get timestamped output e.g.
Oct 04, 2022 8:24:24 PM se.datadosen.jalbum.AlbumBean prepareMakeAlbum
FINE: clean: 0.01s
Oct 04, 2022 8:24:24 PM se.datadosen.jalbum.AlbumBean fireStatus
FINER: Initializing...
Oct 04, 2022 8:24:24 PM se.datadosen.jalbum.ScriptEnginePool doGet
FINER: Initializing bsh.BshScriptEngine@33b08d49
Cache hit for /Users/robert/Library/JAlbum/skins/Missive/init.groovy
MarkusD

Posts: 761
Registered: 13-Apr-2006
Re: Time stamp in the console
Posted: 4 Oct 22, 21:37   in response to: RobM in response to: RobM
 
  Click to reply to this thread Reply
RobM wrote:
What do you want a timestamp for, everything, making an album, uploading it, running a tool?
I would like to have a time stamp automatically for every line in the console log.

If you set the logging level, in preferences, to FINER you will get timestamped output e.g.
Oct 04, 2022 8:24:24 PM se.datadosen.jalbum.AlbumBean prepareMakeAlbum
FINE: clean: 0.01s
Oct 04, 2022 8:24:24 PM se.datadosen.jalbum.AlbumBean fireStatus
FINER: Initializing...
Oct 04, 2022 8:24:24 PM se.datadosen.jalbum.ScriptEnginePool doGet
FINER: Initializing bsh.BshScriptEngine@33b08d49
Cache hit for /Users/robert/Library/JAlbum/skins/Missive/init.groovy
Yes, I know. But to be honest, the format of that time stamp is just h-o-r-r-i-b-l-e. Who can really read this without getting crazy in second? :-)

I'm just looking in the log of TeamViewer:
2017/03/22 10:14:34.944 13268 15116 G2   Logger started.
2017/03/22 10:14:34.948 13268 15116 G2+  ScopedCom: Attached to thread 15116
2017/03/22 10:14:35.015 13268 15116 G2+  GetSimpleDisplayCertNameFromFile: Found cert name: 'TeamViewer'.


So, I'm not the only person in the universe using a readable time stamp in logs. ;-)

Thanks, Markus
JeffTucker

Posts: 8,096
Registered: 31-Jan-2006
Re: Time stamp in the console
Posted: 4 Oct 22, 21:40   in response to: RobM in response to: RobM
 
  Click to reply to this thread Reply
Among the developers, I suspect the only one who's looking for efficiency improvements is David, and I suspect he's not using the console for that.

For skin development, none of it matters. What takes time is processing the images, and especially processing videos. If you're just bouncing through the skin templates and producing pages, it all happens so fast, it's not worth worrying about timings.

When I converted all my skins from BeanShell to Groovy, I was curious about whether it would affect the processing time. So, I just hit F9 about 10 times in a row, and looked at the console to see how long each build took. The results were typically something like 0.276 seconds vs. 0.275 seconds.

And there's unlikely to be anything in my code I could change to make it faster.
MarkusD

Posts: 761
Registered: 13-Apr-2006
Re: Time stamp in the console
Posted: 4 Oct 22, 21:56   in response to: JeffTucker in response to: JeffTucker
 
  Click to reply to this thread Reply
The album which I compile very often takes about 13 minutes and longer, even I haven't changed, added or delete one picture, video, PDF or any other object. And the bad thing is not the time it takes but the sound/noise the HDD makes during this process, that sound goes down your spine, it sound for minutes like the disc will crash in a second.

So I'm not interested how long the build time is, but how long some specific tasks last.

You remember maybe that I recently changed the logging level from "Warning" to "ALL" and some of my pictures where marked with the variants resolution. That was only to try to get more info what does take so long to compile an album with just 6,354 pictures, 519 videos and 1,345 others. I would call that a small album. Other users here are sometimes talking about albums with 100,000 objects and more. It would take days to compile such an album here.

So, I'm not sure, is it "safe" to use the logging level "ALL" again (with JA 29rc)? And not getting pictures watermarked with the variants resolution?

Or any other tip how I should find out what takes so long to compile an album?

Thanks, Markus
davidekholm

Posts: 3,708
Registered: 18-Oct-2002
Re: Time stamp in the console
Posted: 4 Oct 22, 22:07   in response to: MarkusD in response to: MarkusD
 
  Click to reply to this thread Reply
MarkusD wrote:
The album which I compile very often takes about 13 minutes and longer, even I haven't changed, added or delete one picture, video, PDF or any other object. And the bad thing is not the time it takes but the sound/noise the HDD makes during this process, that sound goes down your spine, it sound for minutes like the disc will crash in a second.

So I'm not interested how long the build time is, but how long some specific tasks last.

You remember maybe that I recently changed the logging level from "Warning" to "ALL" and some of my pictures where marked with the variants resolution. That was only to try to get more info what does take so long to compile an album with just 6,354 pictures, 519 videos and 1,345 others. I would call that a small album. Other users here are sometimes talking about albums with 100,000 objects and more. It would take days to compile such an album here.

So, I'm not sure, is it "safe" to use the logging level "ALL" again (with JA 29rc)? And not getting pictures watermarked with the variants resolution?

Or any other tip how I should find out what takes so long to compile an album?

Thanks, Markus

The most recent beta versions won't put watermarks on your images even with the most verbose logging level. Now that I know what you're looking for, try to isolate whether it's page processing or image processing that takes most of the time. Work on a more modest copy of that huge project in order to save time, then compare the timings for a "Force rebuild" vs just hitting the "Make album" button. The later should be significantly faster naturally. The problem might be skin specific. To isolate that, try another skin. Make your investigations on a modestly sized copy of that huge gallery first. These steps should get you far in isolating the cause.

Observe CPU. If it isn't 100% during the make process, then it's likely IO that slows down the process.

RobM

Posts: 3,947
Registered: 4-Aug-2006
Re: Time stamp in the console
Posted: 4 Oct 22, 22:12   in response to: MarkusD in response to: MarkusD
Helpful
  Click to reply to this thread Reply
Not sure it is recommended but https://stackoverflow.com/questions/24637600/how-to-format-date-in-java-logging
Shows how to change the logger's date format when jAlbum starts:
-Djava.util.logging.SimpleFormatter.format=
What follows the equals sign is specified in
https://docs.oracle.com/javase/8/docs/api/java/util/logging/SimpleFormatter.html#format-java.util.logging.LogRecord-
The time stamp is specified by the %1, example below (I think I got it right!)
(year day month hours:minutes:seconds am/pm
%1$tY %1$td %1$tb %1$tl:%1$tM:%1$tS %1$Tp
RobM

Posts: 3,947
Registered: 4-Aug-2006
Re: Time stamp in the console
Posted: 4 Oct 22, 22:17   in response to: MarkusD in response to: MarkusD
 
  Click to reply to this thread Reply
Two things that might speed things up
1 Don't process videos, create them as you want them and then add them with 'Don't re-encode videos' set.

2. Change the HDD for a SSD - if you can afford the number required (or maybe process on an SSD and then copy the files to the HDD).
davidekholm

Posts: 3,708
Registered: 18-Oct-2002
Re: Time stamp in the console
Posted: 5 Oct 22, 09:24   in response to: RobM in response to: RobM
 
  Click to reply to this thread Reply
Also, pass us a link to the final album and I'll inspect the project settings.
MarkusD

Posts: 761
Registered: 13-Apr-2006
Re: Time stamp in the console
Posted: 5 Oct 22, 19:01   in response to: davidekholm in response to: davidekholm
 
  Click to reply to this thread Reply
davidekholm wrote:
Now that I know what you're looking for, try to isolate whether it's page processing or image processing that takes most of the time. Work on a more modest copy of that huge project in order to save time, then compare the timings for a "Force rebuild" vs just hitting the "Make album" button. The later should be significantly faster naturally. The problem might be skin specific. To isolate that, try another skin. Make your investigations on a modestly sized copy of that huge gallery first. These steps should get you far in isolating the cause.
Jeff, the problem is, if I'm using a modest album everything is kind of OK, regarding time to compile and noise of the HDD.

A "Force rebuild" would be a disaster, this would take weeks, because of all of the videos.

Observe CPU. If it isn't 100% during the make process, then it's likely IO that slows down the process.
The CPU is never going up more than 20%.

Please understand that the long compile time is for an album with no new, no deleted, no changed "objects" (pictures, videos, PDFs etc.) at all. The only thing that has changed are the folder comments (you may remember, the very long comments). And I would expect that this should be done much faster.

But I'm sure we'll find out what is going on. Thanks.
MarkusD

Posts: 761
Registered: 13-Apr-2006
Re: Time stamp in the console
Posted: 5 Oct 22, 19:04   in response to: RobM in response to: RobM
 
  Click to reply to this thread Reply
That helped much!

I use:
 -Djava.util.logging.SimpleFormatter.format="%1$td.%1$tm.%1$tY %1$tH:%1$tM:%1$tS.%1$tL%n"


Which produce something like this:
05.10.2022 19:02:54.386


That is readable. :-)
MarkusD

Posts: 761
Registered: 13-Apr-2006
Re: Time stamp in the console
Posted: 5 Oct 22, 19:10   in response to: RobM in response to: RobM
 
  Click to reply to this thread Reply
RobM wrote:
Two things that might speed things up
1 Don't process videos, create them as you want them and then add them with 'Don't re-encode videos' set.
The 12 minutes to compile the album is without any processed picture or video at all. :-)

2. Change the HDD for a SSD - if you can afford the number required (or maybe process on an SSD and then copy the files to the HDD).
The source (pictures/videos are all on a HDD) and the size of all of this is about 1,5 TB. The C: drive (with all the applications) is already a SDD, and the output folder is also on a SDD. But upgrading my PC with another SDD for the rest is not a good idea, the PC is to old for that. I'll replace the whole thing with a new system where all parts are from the newest generation.
MarkusD

Posts: 761
Registered: 13-Apr-2006
Re: Time stamp in the console
Posted: 5 Oct 22, 19:10   in response to: davidekholm in response to: davidekholm
 
  Click to reply to this thread Reply
davidekholm wrote:
Also, pass us a link to the final album and I'll inspect the project settings.
Here we go: https://www.markus-drueck.de/norge/
RobM

Posts: 3,947
Registered: 4-Aug-2006
Re: Time stamp in the console
Posted: 5 Oct 22, 19:34   in response to: MarkusD in response to: MarkusD
 
  Click to reply to this thread Reply
MarkusD wrote:
The source (pictures/videos are all on a HDD) and the size of all of this is about 1,5 TB.
My guess at what’s slowing it down is JSON data processing. It must be like printing out War and Peace on every album build ;)
MarkusD

Posts: 761
Registered: 13-Apr-2006
Re: Time stamp in the console
Posted: 5 Oct 22, 19:47   in response to: RobM in response to: RobM
 
  Click to reply to this thread Reply
RobM wrote:
What do you want a timestamp for, everything, making an album, uploading it, running a tool?

Most of us only look at the console logs when developing things or debugging a core problem.
I'm more interested in where an issue is than what time it happened.

If you set the logging level, in preferences, to FINER you will get timestamped output e.g.
Oct 04, 2022 8:24:24 PM se.datadosen.jalbum.AlbumBean prepareMakeAlbum
FINE: clean: 0.01s
Oct 04, 2022 8:24:24 PM se.datadosen.jalbum.AlbumBean fireStatus
FINER: Initializing...
Oct 04, 2022 8:24:24 PM se.datadosen.jalbum.ScriptEnginePool doGet
FINER: Initializing bsh.BshScriptEngine@33b08d49
Cache hit for /Users/robert/Library/JAlbum/skins/Missive/init.groovy

I recorded a video of the compile part and the upload part.
https://www.markus-drueck.de/JA/Video_2022-10-05_193234.wmv

Maybe you can spot anything of value. As you can see it took four minutes until the first object was processed. Does that ring a bell on your side? Thanks.

P.S. If the Linux or Mac folks are not able to watch that video, I can put it in an album and process it. Just give me a hint.
Legend
Forum admins
Helpful Answer
Correct Answer

Point your RSS reader here for a feed of the latest messages in all forums