Bestman logs
From CEDPS
Introduction
Examples of Berkeley Storage Manager (BeStMan), an SRM implementation, logging.
September 3, 2008
- Zipped 'raw' log file from pdsfgrid5 (45K)
- Zipped logfile after parsing with NetLogger (32K)
- Example:
ts=2008-08-22T05:35:06.261Z level=Info class=gov.lbl.srm.server.ContainerThread event=ServerReady address=httpg://dmx09.lbl.gov:8444/srm/V2/Se rver tid=Thread-3 ts=2008-08-22T05:35:35.680Z level=Info class=gov.lbl.srm.server.TSRMServer event=incoming.srmPing tid=Thread-7 ts=2008-08-22T05:35:35.690Z level=Info class=gov.lbl.srm.impl.TSRMService event=outcoming.srmPing tid=Thread-7 ts=2008-08-22T05:35:37.237Z level=Info class=gov.lbl.srm.server.TSRMServer event=incoming.srmGetTransferProtocols tid=Thread-11 ts=2008-08-22T05:35:37.247Z level=Info class=gov.lbl.srm.impl.TSRMService event=outcoming.srmGetTransferProtocols tid=Thread-11 ts=2008-08-22T05:35:38.438Z level=Info class=gov.lbl.srm.server.TSRMServer event=incoming.srmGetSpaceTokens tid=Thread-8 ts=2008-08-22T05:35:38.439Z level=Info class=gov.lbl.srm.impl.TSRMService event=outcoming.srmGetSpaceTokens tid=Thread-8 ts=2008-08-22T05:35:38.831Z level=Info class=gov.lbl.srm.server.TSRMServer event=incoming.srmCopy tid=Thread-12 ts=2008-08-22T05:35:38.840Z level=Info class=gov.lbl.srm.server.TUserRequestCopy event=start rid=junmin:0(COPY) tid=Thread-12 ts=2008-08-22T05:35:38.840Z level=Info class=gov.lbl.srm.server.TSRMServer event=list rid=junmin:0(COPY) reqSize=2 overwrite=NEVER fst=null to ken=null rpi=null lt=null tid=Thread-12 ts=2008-08-22T05:35:38.864Z level=Info class=gov.lbl.srm.server.TSRMRequestCopyFromRemote rid=junmin:0(COPY) pos=0 from="gsiftp://dmx09.lbl.go v///tmp/hello.java" pinDur=1200000 to="srm://dmx09.lbl.gov:8444/srm/V2/Server?SFN=/srmcache/junmin/four" event=queued tid=Thread-12 ts=2008-08-22T05:35:38.866Z level=Info class=gov.lbl.srm.server.TSRMRequestCopyFromRemote rid=junmin:0(COPY) pos=0 from="gsiftp://dmx09.lbl.gov///tmp/hello.java" pinD ur=1200000 to="srm://dmx09.lbl.gov:8444/srm/V2/Server?SFN=/srmcache/junmin/four" postInit=true event=scheduled tid=Thread-22 ts=2008-08-22T05:35:38.872Z level=Info class=gov.lbl.srm.server.TSRMRequestCopyFromRemote rid=junmin:0(COPY) pos=1 from="gsiftp://dmx09.lbl.gov///tmp/hello.java" pinD ur=1200000 to="srm://dmx09.lbl.gov:8444/srm/V2/Server?SFN=/srmcache/junmin/five" event=queued tid=Thread-12 ts=2008-08-22T05:35:38.875Z level=Info class=gov.lbl.srm.server.TSRMRequestCopyFromRemote rid=junmin:0(COPY) pos=1 from="gsiftp://dmx09.lbl.gov///tmp/hello.java" pinD ur=1200000 to="srm://dmx09.lbl.gov:8444/srm/V2/Server?SFN=/srmcache/junmin/five" postInit=true event=scheduled tid=Thread-23 ts=2008-08-22T05:35:38.878Z level=Info class=gov.lbl.srm.impl.TSRMService event=outcoming.SrmCopy tid=Thread-12 ts=2008-08-22T05:35:39.807Z level=Info class=gov.lbl.srm.server.TSRMRequestCopyFromRemote event=reqStatus statusCode=SRM_REQUEST_INPROGRESS rid=junmin:0(COPY) pos=1 fr om="gsiftp://dmx09.lbl.gov///tmp/hello.java" pinDur=1200000 to="srm://dmx09.lbl.gov:8444/srm/V2/Server?SFN=/srmcache/junmin/five" exp="null" tid=Thread-23 ts=2008-08-22T05:35:39.810Z level=Info class=gov.lbl.srm.server.TSRMSourceFile event=download rid=junmin:0(COPY) pos=1 from=/junmin/five tid=Thread-23 ts=2008-08-22T05:35:39.813Z level=Info class=gov.lbl.srm.server.TSRMDownloadCommon event=TxfStartsPull path=/junmin/five tid=Thread-23 ts=2008-08-22T05:35:39.827Z level=Info class=gov.lbl.srm.server.TSRMRequestCopyFromRemote event=reqStatus statusCode=SRM_REQUEST_INPROGRESS rid=junmin:0(COPY) pos=0 fr om="gsiftp://dmx09.lbl.gov///tmp/hello.java" pinDur=1200000 to="srm://dmx09.lbl.gov:8444/srm/V2/Server?SFN=/srmcache/junmin/four" exp="null" tid=Thread-22 ts=2008-08-22T05:35:39.830Z level=Info class=gov.lbl.srm.server.TSRMSourceFile event=download rid=junmin:0(COPY) pos=0 from=/junmin/four tid=Thread-22 ts=2008-08-22T05:35:39.831Z level=Info class=gov.lbl.srm.server.TSRMDownloadCommon event=TxfStartsPull path=/junmin/four tid=Thread-22 ts=2008-08-22T05:35:40.590Z level=Info class=gov.lbl.srm.server.TSRMDownloadCommon event=txfSetup path=/junmin/five trustedSize=80 tid=Thread-23 ts=2008-08-22T05:35:40.606Z level=Info class=gov.lbl.srm.server.TSRMDownloadCommon event=txfSetup path=/junmin/four trustedSize=80 tid=Thread-22 ts=2008-08-22T05:35:42.363Z level=Info class=gov.lbl.srm.server.TSRMDownloadCommon event=TxfEndsPull path=/junmin/five tid=Thread-23 ts=2008-08-22T05:35:42.364Z level=Info class=gov.lbl.srm.server.TSRMRequestCopyFromRemote event=reqStatus statusCode=SRM_SUCCESS rid=junmin:0(COPY) pos=1 from="gsiftp: //dmx09.lbl.gov///tmp/hello.java" pinDur=1200000 to="srm://dmx09.lbl.gov:8444/srm/V2/Server?SFN=/srmcache/junmin/five" exp="pinned:/junmin/five" tid=Thread-23 ts=2008-08-22T05:35:42.365Z level=Info class=gov.lbl.srm.server.TSRMRequestCopyFromRemote rid=junmin:0(COPY) pos=1 from="gsiftp://dmx09.lbl.gov///tmp/hello.java" pinD ur=1200000 to="srm://dmx09.lbl.gov:8444/srm/V2/Server?SFN=/srmcache/junmin/five" event=end tid=Thread-23 ts=2008-08-22T05:35:42.422Z level=Info class=gov.lbl.srm.server.TSRMDownloadCommon event=TxfEndsPull path=/junmin/four tid=Thread-22 ts=2008-08-22T05:35:42.423Z level=Info class=gov.lbl.srm.server.TSRMRequestCopyFromRemote event=reqStatus statusCode=SRM_SUCCESS rid=junmin:0(COPY) pos=0 from="gsiftp: //dmx09.lbl.gov///tmp/hello.java" pinDur=1200000 to="srm://dmx09.lbl.gov:8444/srm/V2/Server?SFN=/srmcache/junmin/four" exp="pinned:/junmin/four" tid=Thread-22 ts=2008-08-22T05:35:42.424Z level=Info class=gov.lbl.srm.server.TSRMRequestCopyFromRemote rid=junmin:0(COPY) pos=0 from="gsiftp://dmx09.lbl.gov///tmp/hello.java" pinD ur=1200000 to="srm://dmx09.lbl.gov:8444/srm/V2/Server?SFN=/srmcache/junmin/four" event=end tid=Thread-22 ts=2008-08-22T05:35:53.390Z level=Info class=gov.lbl.srm.server.TSRMServer event=incoming.srmPing tid=Thread-10 ts=2008-08-22T05:35:53.392Z level=Info class=gov.lbl.srm.impl.TSRMService event=outcoming.srmPing tid=Thread-10 ts=2008-08-22T05:35:54.614Z level=Info class=gov.lbl.srm.server.TSRMServer event=incoming.srmGetTransferProtocols tid=Thread-7 ts=2008-08-22T05:35:54.615Z level=Info class=gov.lbl.srm.impl.TSRMService event=outcoming.srmGetTransferProtocols tid=Thread-7 ts=2008-08-22T05:35:54.921Z level=Info class=gov.lbl.srm.server.TSRMServer event=incoming.srmGetSpaceTokens tid=Thread-11 ts=2008-08-22T05:35:54.922Z level=Info class=gov.lbl.srm.impl.TSRMService event=outcoming.srmGetSpaceTokens tid=Thread-11 ts=2008-08-22T05:35:55.845Z level=Info class=gov.lbl.srm.server.TSRMServer event=incoming.srmCopy tid=Thread-8 ts=2008-08-22T05:35:55.846Z level=Info class=gov.lbl.srm.server.TUserRequestCopy event=start rid=junmin:1(COPY) tid=Thread-8 ts=2008-08-22T05:35:55.846Z level=Info class=gov.lbl.srm.server.TSRMServer event=list rid=junmin:1(COPY) reqSize=2 overwrite=NEVER fst=null token=null rpi=null lt=nul l tid=Thread-8 ts=2008-08-22T05:35:55.848Z level=Info class=gov.lbl.srm.server.TSRMRequestCopyFromRemote rid=junmin:1(COPY) pos=0 from="gsiftp://dmx09.lbl.gov///tmp/hello.java" pinD ur=1200000 to="srm://dmx09.lbl.gov:8444/srm/V2/Server?SFN=/srmcache/junmin/four" event=queued tid=Thread-8 ts=2008-08-22T05:35:55.849Z level=Info class=gov.lbl.srm.server.TSRMRequestCopyFromRemote rid=junmin:1(COPY) pos=0 from="gsiftp://dmx09.lbl.gov///tmp/hello.java" pinD ur=1200000 to="srm://dmx09.lbl.gov:8444/srm/V2/Server?SFN=/srmcache/junmin/four" postInit=true event=scheduled tid=Thread-42 ts=2008-08-22T05:35:55.850Z level=Info class=gov.lbl.srm.server.TSRMRequestCopyFromRemote event=reqStatus statusCode=SRM_DUPLICATION_ERROR rid=junmin:1(COPY) pos=0 fro m="gsiftp://dmx09.lbl.gov///tmp/hello.java" pinDur=1200000 exp="file already exists, and no overwrite is allowed from the request." tid=Thread-42 ts=2008-08-22T05:35:55.850Z level=Info class=gov.lbl.srm.server.TSRMRequestCopyFromRemote event=reqStatus statusCode=SRM_RELEASED rid=junmin:0(COPY) pos=0 from="gsiftp ://dmx09.lbl.gov///tmp/hello.java" pinDur=1200000 to="srm://dmx09.lbl.gov:8444/srm/V2/Server?SFN=/srmcache/junmin/four" exp="system clears pin" tid=Thread-42 ts=2008-08-22T05:35:55.851Z level=Info class=gov.lbl.srm.server.TSRMRequestCopyFromRemote rid=junmin:1(COPY) pos=1 from="gsiftp://dmx09.lbl.gov///tmp/hello.java" pinD ur=1200000 to="srm://dmx09.lbl.gov:8444/srm/V2/Server?SFN=/srmcache/junmin/five" event=queued tid=Thread-8 ts=2008-08-22T05:35:55.852Z level=Info class=gov.lbl.srm.impl.TSRMService event=outcoming.SrmCopy tid=Thread-8 ts=2008-08-22T05:35:55.853Z level=Info class=gov.lbl.srm.server.TSRMRequestCopyFromRemote rid=junmin:1(COPY) pos=1 from="gsiftp://dmx09.lbl.gov///tmp/hello.java" pinD ur=1200000 to="srm://dmx09.lbl.gov:8444/srm/V2/Server?SFN=/srmcache/junmin/five" postInit=true event=scheduled tid=Thread-43 ts=2008-08-22T05:35:55.854Z level=Info class=gov.lbl.srm.server.TSRMRequestCopyFromRemote event=reqStatus statusCode=SRM_DUPLICATION_ERROR rid=junmin:1(COPY) pos=1 fro m="gsiftp://dmx09.lbl.gov///tmp/hello.java" pinDur=1200000 exp="file already exists, and no overwrite is allowed from the request." tid=Thread-43 ts=2008-08-22T05:35:55.854Z level=Info class=gov.lbl.srm.server.TSRMRequestCopyFromRemote event=reqStatus statusCode=SRM_RELEASED rid=junmin:0(COPY) pos=1 from="gsiftp ://dmx09.lbl.gov///tmp/hello.java" pinDur=1200000 to="srm://dmx09.lbl.gov:8444/srm/V2/Server?SFN=/srmcache/junmin/five" exp="system clears pin" tid=Thread-43 ts=2008-08-22T05:38:58.264Z level=Info class=gov.lbl.srm.server.TSRMServer event=incoming.srmPing tid=Thread-12 ts=2008-08-22T05:38:58.266Z level=Info class=gov.lbl.srm.impl.TSRMService event=outcoming.srmPing tid=Thread-12 ts=2008-08-22T05:38:59.408Z level=Info class=gov.lbl.srm.server.TSRMServer event=incoming.srmGetTransferProtocols tid=Thread-10 ts=2008-08-22T05:38:59.409Z level=Info class=gov.lbl.srm.impl.TSRMService event=outcoming.srmGetTransferProtocols tid=Thread-10 ts=2008-08-22T05:39:00.352Z level=Info class=gov.lbl.srm.server.TSRMServer event=incoming.srmGetSpaceTokens tid=Thread-7 ts=2008-08-22T05:39:00.354Z level=Info class=gov.lbl.srm.impl.TSRMService event=outcoming.srmGetSpaceTokens tid=Thread-7 ts=2008-08-22T05:39:00.662Z level=Info class=gov.lbl.srm.server.TSRMServer event=incoming.srmCopy tid=Thread-11 ts=2008-08-22T05:39:00.664Z level=Info class=gov.lbl.srm.server.TUserRequestCopy event=start rid=junmin:2(COPY) tid=Thread-11 ts=2008-08-22T05:39:00.664Z level=Info class=gov.lbl.srm.server.TSRMServer event=list rid=junmin:2(COPY) reqSize=2 overwrite=NEVER fst=null token=null rpi=null lt=nul l tid=Thread-11 ts=2008-08-22T05:39:00.667Z level=Info class=gov.lbl.srm.server.TSRMRequestCopyToRemote rid=junmin:2(COPY) pos=0 from="file:///tmp/hello.java" pinDur=-1 to="gsiftp:// dmx09.lbl.gov///tmp/copied0" tgt="gsiftp://dmx09.lbl.gov///tmp/copied0" event=queued tid=Thread-11 ts=2008-08-22T05:39:00.668Z level=Info class=gov.lbl.srm.server.TSRMRequestCopyToRemote rid=junmin:2(COPY) pos=0 from="file:///tmp/hello.java" pinDur=-1 to="gsiftp:// dmx09.lbl.gov///tmp/copied0" tgt="gsiftp://dmx09.lbl.gov///tmp/copied0" postInit=true event=scheduled tid=Thread-44 ts=2008-08-22T05:39:00.670Z level=Info class=gov.lbl.srm.server.TSRMRequestCopyToRemote event=reqStatus statusCode=SRM_REQUEST_INPROGRESS rid=junmin:2(COPY) pos=0 from ="file:///tmp/hello.java" pinDur=-1 tgt="gsiftp://dmx09.lbl.gov///tmp/copied0" exp="null" tid=Thread-44 ts=2008-08-22T05:39:00.670Z level=Info class=gov.lbl.srm.server.TSRMRequestCopyToRemote event=upload rid=junmin:2(COPY) pos=0 from="hello.java" tid=Thread-44 ts=2008-08-22T05:39:00.670Z level=Info class=gov.lbl.srm.server.TSRMRequestCopyToRemote event=reqStatus statusCode=SRM_FILE_IN_CACHE rid=junmin:2(COPY) pos=0 from="fil e:///tmp/hello.java" pinDur=-1 tgt="gsiftp://dmx09.lbl.gov///tmp/copied0" exp="pin is not enforced for user owned files" tid=Thread-44 ts=2008-08-22T05:39:00.673Z level=Info class=gov.lbl.srm.server.TSRMUploadCommon event=TxfStartsPush path=hello.java tid=Thread-44 ts=2008-08-22T05:39:00.673Z level=Info class=gov.lbl.srm.server.TSRMUploadCommon event=txfSetup path=hello.java trustedSize=80 tid=Thread-44 ts=2008-08-22T05:39:00.676Z level=Info class=gov.lbl.srm.server.TSRMRequestCopyToRemote rid=junmin:2(COPY) pos=1 from="file:///tmp/test" pinDur=-1 to="gsiftp://dmx09. lbl.gov///tmp/copied1" tgt="gsiftp://dmx09.lbl.gov///tmp/copied1" event=queued tid=Thread-11 ts=2008-08-22T05:39:00.676Z level=Info class=gov.lbl.srm.impl.TSRMService event=outcoming.SrmCopy tid=Thread-11 ts=2008-08-22T05:39:00.681Z level=Info class=gov.lbl.srm.server.TSRMRequestCopyToRemote rid=junmin:2(COPY) pos=1 from="file:///tmp/test" pinDur=-1 to="gsiftp://dmx09. lbl.gov///tmp/copied1" tgt="gsiftp://dmx09.lbl.gov///tmp/copied1" postInit=true event=scheduled tid=Thread-45 ts=2008-08-22T05:39:00.682Z level=Info class=gov.lbl.srm.server.TSRMRequestCopyToRemote event=reqStatus statusCode=SRM_REQUEST_INPROGRESS rid=junmin:2(COPY) pos=1 from ="file:///tmp/test" pinDur=-1 tgt="gsiftp://dmx09.lbl.gov///tmp/copied1" exp="null" tid=Thread-45 ts=2008-08-22T05:39:00.682Z level=Info class=gov.lbl.srm.server.TSRMRequestCopyToRemote event=upload rid=junmin:2(COPY) pos=1 from="test" tid=Thread-45 ts=2008-08-22T05:39:00.682Z level=Info class=gov.lbl.srm.server.TSRMRequestCopyToRemote event=reqStatus statusCode=SRM_FILE_IN_CACHE rid=junmin:2(COPY) pos=1 from="fil e:///tmp/test" pinDur=-1 tgt="gsiftp://dmx09.lbl.gov///tmp/copied1" exp="pin is not enforced for user owned files" tid=Thread-45 ts=2008-08-22T05:39:00.683Z level=Info class=gov.lbl.srm.server.TSRMUploadCommon event=TxfStartsPush path=test tid=Thread-45 ts=2008-08-22T05:39:00.683Z level=Info class=gov.lbl.srm.server.TSRMUploadCommon event=txfSetup path=test trustedSize=80 tid=Thread-45 ts=2008-08-22T05:39:02.605Z level=Info class=gov.lbl.srm.server.TSRMUploadCommon event=TxfEndsPush path=hello.java tid=Thread-44 ts=2008-08-22T05:39:02.606Z level=Info class=gov.lbl.srm.server.TSRMRequestCopyToRemote event=reqStatus statusCode=SRM_SUCCESS rid=junmin:2(COPY) pos=0 from="file:///t mp/hello.java" pinDur=-1 tgt="gsiftp://dmx09.lbl.gov///tmp/copied0" exp="null" tid=Thread-44 ts=2008-08-22T05:39:02.606Z level=Info class=gov.lbl.srm.server.TSRMRequestCopyToRemote rid=junmin:2(COPY) pos=0 from="file:///tmp/hello.java" pinDur=-1 tgt="gsiftp:/ /dmx09.lbl.gov///tmp/copied0" event=end tid=Thread-44 ts=2008-08-22T05:39:02.662Z level=Info class=gov.lbl.srm.server.TSRMUploadCommon event=TxfEndsPush path=test tid=Thread-45 ts=2008-08-22T05:39:02.662Z level=Info class=gov.lbl.srm.server.TSRMRequestCopyToRemote event=reqStatus statusCode=SRM_SUCCESS rid=junmin:2(COPY) pos=1 from="file:///t mp/test" pinDur=-1 tgt="gsiftp://dmx09.lbl.gov///tmp/copied1" exp="null" tid=Thread-45 ts=2008-08-22T05:39:02.662Z level=Info class=gov.lbl.srm.server.TSRMRequestCopyToRemote rid=junmin:2(COPY) pos=1 from="file:///tmp/test" pinDur=-1 tgt="gsiftp://dmx09 .lbl.gov///tmp/copied1" event=end tid=Thread-45
