It seems that the problem was that the sessionId was not set inmediately after...
It seems that the problem was that the sessionId was not set inmediately after the login of the user.
Now logs look like:
2020-04-03T06:02:03.065Z [info]: Login done successfully.
username : reader
plugin : db
2020-04-03T06:02:03.066Z [debug]: Init cache for userreader
2020-04-03T06:02:03.066Z [info]: Init cache for user
sessionId : 9d1614e3-aab0-4a2b-b25b-231275f0d7b3
username : reader
2020-04-03T06:02:03.200Z [info]: getSessionInformation succeed
sessionId : 9d1614e3-aab0-4a2b-b25b-231275f0d7b3
username : reader
2020-04-03T06:02:03.201Z [info]: username => cache
sessionId : 9d1614e3-aab0-4a2b-b25b-231275f0d7b3
key : username
2020-04-03T06:02:03.204Z [info]: [cache] Username is set
sessionId : 9d1614e3-aab0-4a2b-b25b-231275f0d7b3
username : reader
isAdministrator : false
2020-04-03T06:02:03.205Z [debug]: [cache] Retrieving datacollections by sessionId
sessionId : 9d1614e3-aab0-4a2b-b25b-231275f0d7b3
2020-04-03T06:02:03.207Z [debug]: http://localhost:8080/icat/entityManager?sessionId=9d1614e3-aab0-4a2b-b25b-231275f0d7b3&query=SELECT distinct(dc) from DataCollection dc JOIN dc.dataCollectionDatasets dcds JOIN dcds.dataset ds where dc.doi is not null include dc.parameters p, p.type, dc.dataCollectionDatasets dcds, dcds.dataset&server=http://localhost:8080
method : getDataColletionsBySessionId
2020-04-03T06:02:03.208Z [debug]: [cache] Retrieving investigations by sessionId
sessionId : 9d1614e3-aab0-4a2b-b25b-231275f0d7b3
2020-04-03T06:02:03.208Z [debug]: getInvestigationsBySessionId
query : http://localhost:8080/icat/entityManager?sessionId=9d1614e3-aab0-4a2b-b25b-231275f0d7b3&query=select distinct investigation from Investigation investigation , investigation.investigationUsers as investigationUserPivot , investigationUserPivot.user as investigationUser where investigationUser.name = 'reader' order by investigation.startDate DESC include investigation.investigationInstruments investigationInstruments, investigationInstruments.instrument instrument, investigation.parameters p, p.type&server=http://localhost:8080
2020-04-03T06:02:03.364Z [debug]: [cache] Retrieved 0 investigations from ICAT by sessionId.
sessionId : 9d1614e3-aab0-4a2b-b25b-231275f0d7b3
username : reader
2020-04-03T06:02:03.364Z [info]: myInvestigations => cache
sessionId : 9d1614e3-aab0-4a2b-b25b-231275f0d7b3
key : myInvestigations
2020-04-03T06:02:03.907Z [debug]: [cache] Retrieved 12 datacollections from ICAT by sessionId.
sessionId : 9d1614e3-aab0-4a2b-b25b-231275f0d7b3
username : reader
2020-04-03T06:02:03.910Z [info]: datacollections => cache
sessionId : 9d1614e3-aab0-4a2b-b25b-231275f0d7b3
key : datacollections
It refers to #108 (closed)