Autorun Pipeline fails

[Sven Prevrhal]

At Review and Archival, Autorun fails. Status on the Workflow Details page says:

Current step id	4b
Step Description   This err file contains:	See /tmp/xnat/cache/test//Unknown/AutoRun.err for errors

xnat@rs210205:~$ less /tmp/xnat/cache/test//Unknown/AutoRun.err

--------------------------------------------------------------------------------------

log4j:ERROR setFile(null,true) call failed.

java.io.FileNotFoundException: logs/pipeline.log (No such file or directory)

        at java.io.FileOutputStream.open(Native Method)

        at java.io.FileOutputStream.<init>(FileOutputStream.java:221)

        at java.io.FileOutputStream.<init>(FileOutputStream.java:142)

        at org.apache.log4j.FileAppender.setFile(FileAppender.java:294)

        at org.apache.log4j.RollingFileAppender.setFile(RollingFileAppender.java:207)

        at org.apache.log4j.FileAppender.activateOptions(FileAppender.java:165)

        at org.apache.log4j.config.PropertySetter.activate(PropertySetter.java:307)

        at org.apache.log4j.config.PropertySetter.setProperties(PropertySetter.java:172)

        at org.apache.log4j.config.PropertySetter.setProperties(PropertySetter.java:104)

        at org.apache.log4j.PropertyConfigurator.parseAppender(PropertyConfigurator.java:809)

        at org.apache.log4j.PropertyConfigurator.parseCategory(PropertyConfigurator.java:735)

        at org.apache.log4j.PropertyConfigurator.configureRootCategory(PropertyConfigurator.java:615)

Where should that file logs/pipeline.log be? Should I create it?

This is XNAT 1.6.4

Thanks!

Sven

[Herrick, Rick]

It should be in the logs folder under your pipeline installation. I’d guess that there are permissions error on the pipeline folder and the pipeline process can’t create the logs folder under the pipeline folder or, if the logs folder is there, the pipeline process can’t write to that folder.

-- 

Rick Herrick

Sr. Programmer/Analyst

Neuroinformatics Research Group

Washington University School of Medicine

(314) 740-5961

--
You received this message because you are subscribed to the Google Groups "xnat_discussion" group.
To unsubscribe from this group and stop receiving emails from it, send an email to xnat_discussi...@googlegroups.com.
To post to this group, send email to xnat_di...@googlegroups.com.
Visit this group at http://groups.google.com/group/xnat_discussion.
For more options, visit https://groups.google.com/d/optout.

---

The material in this message is private and may contain Protected Healthcare Information (PHI). If you are not the intended recipient, be advised that any unauthorized use, disclosure, copying or the taking of any action in reliance on the contents of this information is strictly prohibited. If you have received this email in error, please immediately notify the sender via telephone or return mail.

[Robin Koch]

Am Mittwoch, 8. April 2015 15:56:47 UTC+2 schrieb Sven Prevrhal:

 

xnat@rs210205:~$ less /tmp/xnat/cache/test//Unknown/AutoRun.err--------------------------------------------------------------------------------------

log4j:ERROR setFile(null,true) call failed.

java.io.FileNotFoundException: logs/pipeline.log (No such file or directory)

[...]

Where should that file logs/pipeline.log be? Should I create it?

Are you sure it's supposed to be "pipeline.log" rather than just "pipeline"?

On our local VM there seems to be no pipeline.log at all.
But there is a link logs/pipeline to the folder PIPELINE-PATH/logs.
(Both under "~/Development".)

But than again, I'm just guessing. :-)

Robin

[Herrick, Rick]

By default the name specified to the logging framework is just logs/pipeline.log. The default logging appender takes that name format and adds a date-time stamp to it, so you end up with something like:

PIPELINE-PATH/logs/pipeline_2015_03_20_01_57_20.log

Error messages don’t know what the framework intended to do, so it just outputs the default name template.

-- 

Rick Herrick

Sr. Programmer/Analyst

Neuroinformatics Research Group

Washington University School of Medicine

(314) 740-5961

From: Robin Koch <rko...@googlemail.com>
Reply-To: "xnat_di...@googlegroups.com" <xnat_di...@googlegroups.com>
Date: Wednesday, April 8, 2015 at 9:56 AM
To: "xnat_di...@googlegroups.com" <xnat_di...@googlegroups.com>

--
You received this message because you are subscribed to the Google Groups "xnat_discussion" group.
To unsubscribe from this group and stop receiving emails from it, send an email to xnat_discussi...@googlegroups.com.
To post to this group, send email to xnat_di...@googlegroups.com.
Visit this group at http://groups.google.com/group/xnat_discussion.
For more options, visit https://groups.google.com/d/optout.

[Sven Prevrhal]

Thanks all -

Indeed, the permissions where u=rwx owned by xnat, group xnat.

Will this do?

drwxrwxr-x  2 xnat xnat  4096 Apr  8 16:27 logs

 Cheers,

Sven

--
You received this message because you are subscribed to a topic in the Google Groups "xnat_discussion" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/xnat_discussion/vugWKJfq4is/unsubscribe.
To unsubscribe from this group and all its topics, send an email to xnat_discussi...@googlegroups.com.

[Herrick, Rick]

You could TRY changing the permissions to 777 just in case the pipeline is somehow being launched as another user but I doubt that’s it. Have you checked your available disk space on the server?

-- 

Rick Herrick

Sr. Programmer/Analyst

Neuroinformatics Research Group

Washington University School of Medicine

(314) 740-5961

[Sven Prevrhal]

Disk space is fine. I just tried, it's actually working now, with 775. The crypted user name XNATRestClient uses seems to be part of the xnat group.

Many thanks!

Sven

[Robin Koch]

Well, I found which codeline is responsible for that entry:

%pipeline-path%/lib/xnat-rest-client-1.6.2-SNAPSHOT.jar/log4j.properties

Line 5 there says:

log4j.appender.nrgAppender.File=logs/pipeline.log

In xnat-rest-client-1.6.4.jar there is

log4j.appender.nrgAppender.File=xnat-rest-client.log

instead.

Changing the jar (and therefor using no subfolder) alters the error message from "(No such file or directory)" to "Permission denied".

Although permissions are, of course, granted.

So... no really helping, but at least we know *who* fails logging. That's a start...

I also tried to set the logging level to FATAL to prevent logging as far as possible, but the error stays.

Robin

[Robin Koch]

Ok, I was able solve this by changing the path inside of the xnat-rest-client-1.6.4.jar/log4j.properties to an absolute path.
But the first log files I created appear to be ~10MB!

First 10 of 17937 lines:

DEBUG main httpclient.wire.content - << "[0x0][\n]"
DEBUG main httpclient.wire.content - << "[0x0][0x9][0x0][0xc][0x0][0xf][0x0][0x10][0x0][0xb][0x0][0x7][0x0][0x5][0x0][0x7][0x0][\n]"
DEBUG main httpclient.wire.content - << "[0x0][0x9][0x0][0x6][0x0][0x3][0x0][0x9][0x0][\r][0x0][0xf][0x0][0x11][0x0][\r]"
DEBUG main httpclient.wire.content - << "[0x0][0x9][0x0][0xc][0x0][0x15][0x0]![0x0][0x1e][0x0][\n]"
DEBUG main httpclient.wire.content - << "[0x0][0x8][0x0][0x8][0x0][0x17][0x0] [0x0][0x1a][0x0][0x13][0x0][0xf][0x0][\r][0x0][0xb][0x0][0x11][0x0][0x13][0x0][0xe][0x0][\r][0x0][0x12][0x0][0x14][0x0][0xe][0x0][0xb][0x0][0x13][0x0][0x1e][0x0]%[0x0]'[0x0])[0x0],[0x0])[0x0][0x1d][0x0][0xf][0x0][0x8][0x0][0x5][0x0][0xb][0x0][0x19][0x0][0x1b][0x0][0x10][0x0][0x2][0x0][0x8][0x0][0x16][0x0],[0x0]@[0x0]L[0x0]Q[0x0]Q[0x0]R[0x0]V[0x0]\[0x0]^[0x0]\[0x0]Y[0x0]W[0x0]U[0x0]R[0x0]Q[0x0]T[0x0]V[0x0]T[0x0]S[0x0]W[0x0]\[0x0]V[0x0]F[0x0];[0x0]C[0x0]V[0x0]^[0x0]R[0x0]@[0x0];[0x0]G[0x0]R[0x0]R[0x0]J[0x0]F[0x0]F[0x0]B[0x0]:[0x0]7[0x0]?[0x0]H[0x0]G[0x0]=[0x0]6[0x0]9[0x0]@[0x0]D[0x0]G[0x0]K[0x0]L[0x0]E[0x0]9[0x0]3[0x0]5[0x0]7[0x0]0[0x0]![0x0][0x13][0x0][0xc][0x0][\n]"
DEBUG main httpclient.wire.content - << "[0x0][0x10][0x0][0x19][0x0][0x1a][0x0][0x14][0x0][0x12][0x0][0x1b][0x0]*[0x0]:[0x0]J[0x0]V[0x0]S[0x0]8[0x0][0x17][0x0][0xf][0x0]&[0x0]A[0x0]?[0x0] [0x0][0x3][0x0][0x5][0x0][0x7][0x0][0x17][0x0][0x1d][0x0][0x19][0x0][0x11][0x0][\r][0x0][0xe]"
DEBUG main httpclient.wire.content - << "[0x0][0xc][0x0][0x9][0x0][\n]"
DEBUG main httpclient.wire.content - << "[0x0][0x12][0x0][0x1c][0x0]'[0x0]6[0x0]J[0x0]Z[0x0]b[0x0]f[0x0]j[0x0]g[0x0]V[0x0]@[0x0]>[0x0]X[0x0][0x80][0x0][0x9b][0x0][0xa1][0x0][0x9e][0x0][0x9e][0x0][0xa0][0x0][0xa0][0x0][0xa0][0x0][0xa3][0x0][0xa7][0x0][0xa5][0x0][0x9e][0x0][0x99][0x0][0x9a][0x0][0x9b][0x0][0x99][0x0][0x9a][0x0][0xa1][0x0][0xab][0x0][0xab][0x0][0xa2][0x0][0x9c][0x0][0xa1][0x0][0xaa][0x0][0xaa][0x0][0x9f][0x0][0x92][0x0][0x89][0x0]}[0x0]h[0x0]M[0x0]5[0x0]([0x0]%[0x0]$[0x0]$[0x0]![0x0][0x1c][0x0][0x16][0x0][0x15][0x0][0x1a][0x0] [0x0] [0x0][0x1b][0x0][0x16][0x0][0x17][0x0][0x19][0x0][0x1c][0x0] [0x0]%[0x0]*[0x0]-[0x0],[0x0].[0x0]3[0x0]<[0x0]E[0x0]O[0x0]\[0x0]h[0x0]v[0x0][0x88][0x0][0x9b][0x0][0xa6][0x0][0xa6][0x0][0xa0][0x0][0x9e][0x0][0xa0][0x0][0xa2][0x0][0xa3][0x0][0xa4][0x0][0xa4][0x0][0x9f][0x0][0x95][0x0][0x8f][0x0][0x91][0x0][0x96][0x0][0x99][0x0][0x9a][0x0][0x9b][0x0][0x9a][0x0][0x97][0x0][0x96][0x0][0x98][0x0][0x9b][0x0][0x9a][0x0][0x99][0x0][0x9a][0x0][0x9e][0x0][0x9f][0x0][0x9c][0x0][0x9a][0x0][0x9c][0x0][0x9f][0x0][0xa1][0x0][0x9f][0x0][0x9c][0x0][0x99][0x0][0x99][0x0][0x9d][0x0][0xa0][0x0][0xa0][0x0][0x9d][0x0][0x9b][0x0][0x9a][0x0][0x9a][0x0][0x9b][0x0][0x9d][0x0][0xa1][0x0][0xa3][0x0][0xa4]"
DEBUG main httpclient.wire.content - << "[0x0][0xa4][0x0][0xa3][0x0][0xa2][0x0][0xa2][0x0][0xa4][0x0][0xa4][0x0][0xa2][0x0][0x9e][0x0][0x9d][0x0][0xa1][0x0][0xa5][0x0][0xa6][0x0][0xa5][0x0][0xa4][0x0][0xa4][0x0][0xa5][0x0][0xa6][0x0][0xa7][0x0][0xa9][0x0][0xa9][0x0][0xa8][0x0][0xa7][0x0][0xa6][0x0][0xa6][0x0][0xa6][0x0][0xa9][0x0][0xac][0x0][0xac][0x0][0xaa][0x0][0xa9][0x0][0xa9][0x0][0xa7][0x0][0xa6][0x0][0xab][0x0][0xab][0x0][0x97][0x0]m[0x0]E[0x0]5[0x0]=[0x0]P[0x0]a[0x0]f[0x0][[0x0]B[0x0]%[0x0][0xf][0x0][0x6][0x0][0x8][0x0][0x10][0x0][0x13][0x0][0xc][0x0][0x9][0x0][0x14][0x0]$[0x0]#[0x0][0xb][0x0][\r][0x0][0x8][0x0][0x13][0x0]([0x0]*[0x0][0x1b][0x0][0x9][0x0][0xb][0x0])[0x0]R[0x0]j[0x0]h[0x0]c[0x0]c[0x0]X[0x0]8[0x0][0x14][0x0][\n]"
DEBUG main httpclient.wire.content - << "[0x0][0x12][0x0][0x1d][0x0][0x18][0x0][0xb][0x0][0x4][0x0][\r][0x0][0x1f][0x0]-[0x0]5[0x0];[0x0]A[0x0]C[0x0]@[0x0]>[0x0]A[0x0]G[0x0]L[0x0]S[0x0]Z[0x0]X[0x0]K[0x0]>[0x0]>[0x0]H[0x0]Q[0x0]R[0x0]P[0x0]P[0x0]R[0x0]R[0x0]N[0x0]H[0x0]H[0x0]Q[0x0][[0x0]][0x0]X[0x0]T[0x0]X[0x0]][0x0][[0x0]Q[0x0]H[0x0]G[0x0]L[0x0]P[0x0]O[0x0]H[0x0]A[0x0]>[0x0]B[0x0]I[0x0]L"

So maybe it was a good thing he wasn't able to create them. :-)
Especially since it wasn't fatal.

Robin

[Herrick, Rick]

You can change the logging level in log4j.properties as well. The default set in the pipeline log4j.properties (the one at the root level of the pipeline folder) is DEBUG. Try changing that from this:

log4j.rootLogger=debug, nrgAppender

To this:

log4j.rootLogger=WARN, nrgAppender

I’m not really sure why the REST client log4j.properties is changing things for you. That should affect the overall pipeline log output.

Newer versions of the pipeline engine actually use the XNAT data client (XDC) instead of the XNAT REST client. The REST client uses older deprecated dependencies.

-- 

Rick Herrick

Sr. Programmer/Analyst

Neuroinformatics Research Group

Washington University School of Medicine

(314) 740-5961

From: Robin Koch <rko...@googlemail.com>
Reply-To: "xnat_di...@googlegroups.com" <xnat_di...@googlegroups.com>
Date: Monday, April 20, 2015 at 9:59 AM
To: "xnat_di...@googlegroups.com" <xnat_di...@googlegroups.com>
Subject: [XNAT Discussion] Re: Autorun Pipeline fails

--
You received this message because you are subscribed to the Google Groups "xnat_discussion" group.
To unsubscribe from this group and stop receiving emails from it, send an email to xnat_discussi...@googlegroups.com.
To post to this group, send email to xnat_di...@googlegroups.com.
Visit this group at http://groups.google.com/group/xnat_discussion.
For more options, visit https://groups.google.com/d/optout.