title: Strange timeout while reading from mysql in Spring Boot
body: <p>Notice the huge jump in time before the last two lines:</p>
  
  <pre><code>2018-06-15 00:22:38.263 DEBUG zicada-ws --- [nio-8080-exec-2] stractLoadPlanBasedCollectionInitializer : Loading collection: [com.teletopia.tsip.dbhandler.models.CallFlow.moduleList#179]
  2018-06-15 00:22:38.263 DEBUG zicada-ws --- [nio-8080-exec-2] o.h.SQL                                  : select modulelist0_.CF_ID as CF_ID1_11_0_, modulelist0_.MID as MID2_11_0_, modulelist0_.CF_ID as CF_ID1_11_1_, modulelist0_.MID as MID2_11_1_, modulelist0_.description as descript3_11_1_, modulelist0_.tableName as tableNam4_11_1_, modulelist0_1_.answerCallPolicy as answerCa1_0_1_, modulelist0_1_.commonRecordingId as commonRe2_0_1_, modulelist0_1_.fileName as fileName3_0_1_, modulelist0_1_.nextMID as nextMID4_0_1_, modulelist0_1_.waitForComplete as waitForC5_0_1_, modulelist0_2_.customerSpecificModule as customer1_5_1_, modulelist0_2_.nextMID as nextMID2_5_1_, modulelist0_3_.AlertCallerWhenFree as AlertCal1_12_1_, modulelist0_3_.allowExtendedCall as allowExt2_12_1_, modulelist0_3_.announceCall as announce3_12_1_, modulelist0_3_.answerQueuePolicy as answerQu4_12_1_, modulelist0_3_.busyMID as busyMID5_12_1_, modulelist0_3_.busyRecordingType as busyReco6_12_1_, modulelist0_3_.connectedCallTimeout as connecte7_12_1_, modulelist0_3_.connectedCallWarning as connecte8_12_1_, modulelist0_3_.endDate as endDate9_12_1_, modulelist0_3_.givePosition as givePos10_12_1_, modulelist0_3_.givePositionInterval as givePos11_12_1_, modulelist0_3_.AnnounceCallMsgType as Announc12_12_1_, modulelist0_3_.queueingEnabled as queuein13_12_1_, modulelist0_3_.ringTonePolicy as ringTon14_12_1_, modulelist0_3_.smsText as smsText15_12_1_, modulelist0_3_.startDate as startDa16_12_1_, modulelist0_3_.useTrueANumber as useTrue17_12_1_, modulelist0_3_.waitMusic as waitMus18_12_1_, modulelist0_4_.answerCallPolicy as answerCa1_14_1_, modulelist0_4_.destinationNumber as destinat2_14_1_, modulelist0_4_.noAnswerTimer as noAnswer3_14_1_, modulelist0_4_.onBusyNextMID as onBusyNe4_14_1_, modulelist0_4_.onFailNextMID as onFailNe5_14_1_, modulelist0_4_.onNoAnswerNextMID as onNoAnsw6_14_1_, modulelist0_4_.onPassThroughNextMID as onPassTh7_14_1_, modulelist0_4_.passThrough as passThro8_14_1_, modulelist0_4_.useTrueANumber as useTrueA9_14_1_, modulelist0_5_.endDate as endDate1_9_1_, modulelist0_5_.illegalEntryMID as illegalE2_9_1_, modulelist0_5_.startDate as startDat3_9_1_, modulelist0_5_.timeout as timeout4_9_1_, modulelist0_5_.timeoutMID as timeoutM5_9_1_, modulelist0_6_.alertCallerOnOpen as alertCal1_15_1_, modulelist0_6_.closedMID as closedMI2_15_1_, modulelist0_6_.endDate as endDate3_15_1_, modulelist0_6_.manualState as manualSt4_15_1_, modulelist0_6_.openMID as openMID5_15_1_, modulelist0_6_.scheduleDefinition as schedule6_15_1_, modulelist0_6_.scheduleType as schedule7_15_1_, modulelist0_6_.startDate as startDat8_15_1_, modulelist0_6_.ClosedRecordingType as ClosedRe9_15_1_, modulelist0_7_.activeHgListId as activeHg1_6_1_, modulelist0_7_.addToConference as addToCon2_6_1_, modulelist0_7_.announceCall as announce3_6_1_, modulelist0_7_.answerCallPolicy as answerCa4_6_1_, modulelist0_7_.busyMID as busyMID5_6_1_, modulelist0_7_.connectedCallTimeout as connecte6_6_1_, modulelist0_7_.dtmfAcceptCall as dtmfAcce7_6_1_, modulelist0_7_.endDate as endDate8_6_1_, modulelist0_7_.huntGroupStrategy as huntGrou9_6_1_, modulelist0_7_.overflowMID as overflo10_6_1_, modulelist0_7_.overrideDestination as overrid11_6_1_, modulelist0_7_.ringTonePolicy as ringTon12_6_1_, modulelist0_7_.ringingTimeout as ringing13_6_1_, modulelist0_7_.startDate as startDa14_6_1_, modulelist0_7_.useTrueANumber as useTrue15_6_1_, modulelist0_7_.waitMusic as waitMus16_6_1_, case when modulelist0_1_.CF_ID is not null then 1 when modulelist0_2_.CF_ID is not null then 2 when modulelist0_3_.CF_ID is not null then 3 when modulelist0_4_.CF_ID is not null then 4 when modulelist0_5_.CF_ID is not null then 5 when modulelist0_6_.CF_ID is not null then 6 when modulelist0_7_.CF_ID is not null then 7 when modulelist0_.CF_ID is not null then 0 end as clazz_1_ from MID_To_Table modulelist0_ left outer join Announcement modulelist0_1_ on modulelist0_.CF_ID=modulelist0_1_.CF_ID and modulelist0_.MID=modulelist0_1_.MID left outer join CustomerSpecific modulelist0_2_ on modulelist0_.CF_ID=modulelist0_2_.CF_ID and modulelist0_.MID=modulelist0_2_.MID left outer join Queue modulelist0_3_ on modulelist0_.CF_ID=modulelist0_3_.CF_ID and modulelist0_.MID=modulelist0_3_.MID left outer join RouteCall modulelist0_4_ on modulelist0_.CF_ID=modulelist0_4_.CF_ID and modulelist0_.MID=modulelist0_4_.MID left outer join IVR modulelist0_5_ on modulelist0_.CF_ID=modulelist0_5_.CF_ID and modulelist0_.MID=modulelist0_5_.MID left outer join Schedule modulelist0_6_ on modulelist0_.CF_ID=modulelist0_6_.CF_ID and modulelist0_.MID=modulelist0_6_.MID left outer join HuntGroup modulelist0_7_ on modulelist0_.CF_ID=modulelist0_7_.CF_ID and modulelist0_.MID=modulelist0_7_.MID where modulelist0_.CF_ID=?
  2018-06-15 00:22:38.264 DEBUG zicada-ws --- [nio-8080-exec-2] o.h.l.p.e.p.i.ResultSetProcessorImpl     : Preparing collection intializer : [com.teletopia.tsip.dbhandler.models.CallFlow.moduleList#179]
  2018-06-15 00:22:38.264 DEBUG zicada-ws --- [nio-8080-exec-2] o.h.l.p.e.p.i.ResultSetProcessorImpl     : Starting ResultSet row #0
  2018-06-15 00:22:38.265 DEBUG zicada-ws --- [nio-8080-exec-2] e.p.i.CollectionReferenceInitializerImpl : Found row of collection: [com.teletopia.tsip.dbhandler.models.CallFlow.moduleList#179]
  2018-06-15 00:22:38.265 DEBUG zicada-ws --- [nio-8080-exec-2] o.h.l.p.e.p.i.ResultSetProcessorImpl     : Starting ResultSet row #1
  2018-06-15 00:22:38.266 DEBUG zicada-ws --- [nio-8080-exec-2] e.p.i.CollectionReferenceInitializerImpl : Found row of collection: [com.teletopia.tsip.dbhandler.models.CallFlow.moduleList#179]
  2018-06-15 00:22:38.266 DEBUG zicada-ws --- [nio-8080-exec-2] o.h.l.p.e.p.i.ResultSetProcessorImpl     : Starting ResultSet row #2
  2018-06-15 00:22:38.266 DEBUG zicada-ws --- [nio-8080-exec-2] e.p.i.CollectionReferenceInitializerImpl : Found row of collection: [com.teletopia.tsip.dbhandler.models.CallFlow.moduleList#179]
  2018-06-15 00:22:38.266 DEBUG zicada-ws --- [nio-8080-exec-2] o.h.l.p.e.p.i.ResultSetProcessorImpl     : Starting ResultSet row #3
  2018-06-15 00:22:38.266 DEBUG zicada-ws --- [nio-8080-exec-2] e.p.i.CollectionReferenceInitializerImpl : Found row of collection: [com.teletopia.tsip.dbhandler.models.CallFlow.moduleList#179]
  2018-06-15 00:22:38.266 DEBUG zicada-ws --- [nio-8080-exec-2] o.h.e.i.TwoPhaseLoad                     : Resolving associations for [com.teletopia.tsip.dbhandler.models.Announcement#component[callFlowId,moduleId]{callFlowId=179, moduleId=1}]
  2018-06-15 00:22:38.266 DEBUG zicada-ws --- [nio-8080-exec-2] o.h.e.i.TwoPhaseLoad                     : Done materializing entity [com.teletopia.tsip.dbhandler.models.Announcement#component[callFlowId,moduleId]{callFlowId=179, moduleId=1}]
  2018-06-15 00:22:38.266 DEBUG zicada-ws --- [nio-8080-exec-2] o.h.e.i.TwoPhaseLoad                     : Resolving associations for [com.teletopia.tsip.dbhandler.models.Announcement#component[callFlowId,moduleId]{callFlowId=179, moduleId=2}]
  2018-06-15 00:22:38.266 DEBUG zicada-ws --- [nio-8080-exec-2] o.h.e.i.TwoPhaseLoad                     : Done materializing entity [com.teletopia.tsip.dbhandler.models.Announcement#component[callFlowId,moduleId]{callFlowId=179, moduleId=2}]
  2018-06-15 00:22:38.266 DEBUG zicada-ws --- [nio-8080-exec-2] o.h.e.i.TwoPhaseLoad                     : Resolving associations for [com.teletopia.tsip.dbhandler.models.Schedule#component[callFlowId,moduleId]{callFlowId=179, moduleId=3}]
  2018-06-15 00:22:38.266 DEBUG zicada-ws --- [nio-8080-exec-2] o.h.e.i.TwoPhaseLoad                     : Done materializing entity [com.teletopia.tsip.dbhandler.models.Schedule#component[callFlowId,moduleId]{callFlowId=179, moduleId=3}]
  2018-06-15 00:22:38.266 DEBUG zicada-ws --- [nio-8080-exec-2] o.h.e.i.TwoPhaseLoad                     : Resolving associations for [com.teletopia.tsip.dbhandler.models.Queue#component[callFlowId,moduleId]{callFlowId=179, moduleId=4}]
  2018-06-15 00:22:38.266 DEBUG zicada-ws --- [nio-8080-exec-2] o.h.e.i.TwoPhaseLoad                     : Done materializing entity [com.teletopia.tsip.dbhandler.models.Queue#component[callFlowId,moduleId]{callFlowId=179, moduleId=4}]
  2018-06-15 00:22:38.266 DEBUG zicada-ws --- [nio-8080-exec-2] o.h.e.l.i.CollectionLoadContext          : 1 collections were found in result set for role: com.teletopia.tsip.dbhandler.models.CallFlow.moduleList
  2018-06-15 00:22:38.267 DEBUG zicada-ws --- [nio-8080-exec-2] o.h.e.l.i.CollectionLoadContext          : Collection fully initialized: [com.teletopia.tsip.dbhandler.models.CallFlow.moduleList#179]
  2018-06-15 00:22:38.267 DEBUG zicada-ws --- [nio-8080-exec-2] o.h.e.l.i.CollectionLoadContext          : 1 collections initialized for role: com.teletopia.tsip.dbhandler.models.CallFlow.moduleList
  2018-06-15 00:23:09.883 DEBUG zicada-ws --- [nio-8080-exec-2] o.h.r.j.i.ResourceRegistryStandardImpl   : HHH000387: ResultSet's statement was not registered
  2018-06-15 00:23:09.883 DEBUG zicada-ws --- [nio-8080-exec-2] stractLoadPlanBasedCollectionInitializer : Done loading collection
  </code></pre>
  
  <p>This occurs intermittently, but when it occurs, its always on that statement.</p>
  
  <p>Callflow</p>
  
  <pre><code>@Entity
  @Table(name = "CallFlow")
  public class CallFlow {
      @Id
      @GeneratedValue(strategy = GenerationType.IDENTITY)
      @Column(name = "CF_ID", nullable = false)
      private long callFlowId;
      @Column(name = "FirstMID")
      private Long firstMID;
      private String description;
      private Date startDate;
      private Date changeDate;
      private Date endDate;
  
      @OneToMany(mappedBy = "id.callFlowId", fetch = FetchType.EAGER, cascade = CascadeType.ALL)
      private Set&lt;Module&gt; moduleList;
  
      public long getCallFlowId() {
          return callFlowId;
      }
  
      public void setCallFlowId(long callFlowId) {
          this.callFlowId = callFlowId;
      }
  
      public Long getFirstMID() {
          return firstMID;
      }
  
      public void setFirstMID(Long firstMID) {
          this.firstMID = firstMID;
      }
  
      public String getDescription() {
          return description;
      }
  
      public Date getStartDate() {
          return startDate;
      }
  
      public Date getChangeDate() {
          return changeDate;
      }
  
      public void setChangeDate(Date changeDate) {
          this.changeDate = changeDate;
      }
  
      public Date getEndDate() {
          return endDate;
      }
  
      public void setEndDate(Date endDate) {
          this.endDate = endDate;
      }
  
      public Set&lt;Module&gt; getModuleList() {
          return moduleList;
      }
  
      public void setModuleList(Set&lt;Module&gt; moduleList) {
          this.moduleList = moduleList;
      }
  
      public void setStartDate(Date startDate) {
          if (startDate == null)
              startDate = Calendar.getInstance().getTime();
          this.startDate = startDate;
      }
  
      public void setDescription(String description) {
          if (description == null)
              description = "";
          this.description = description;
      }
  }
  </code></pre>
  
  <p>Module</p>
  
  <pre><code>@Entity
  @Table(name = "MID_To_Table")
  @Inheritance(strategy=InheritanceType.JOINED)
  @JsonIgnoreProperties(ignoreUnknown = true)
  @JsonTypeInfo(
          use = JsonTypeInfo.Id.NAME,
          include = JsonTypeInfo.As.PROPERTY,
          property = "tableName"
  )
  @JsonSubTypes({
          @JsonSubTypes.Type(value = RouteCall.class, name = "RouteCall"),
          @JsonSubTypes.Type(value = Queue.class, name = "Queue"),
          @JsonSubTypes.Type(value = Announcement.class, name = "Announcement"),
          @JsonSubTypes.Type(value = Schedule.class, name = "Schedule"),
          @JsonSubTypes.Type(value = CustomerSpecific.class, name = "CustomerSpecific"),
          @JsonSubTypes.Type(value = IVR.class, name = "IVR")
  })
  public class Module {
      @EmbeddedId
      CallFlowModuleId id;
  
      String tableName;
      String description;
  
      public CallFlowModuleId getId() {
          return id;
      }
  
      public void setId(CallFlowModuleId id) {
          this.id = id;
      }
  
      public String getTableName() {
          return tableName;
      }
  
      public void setTableName(String tableName) {
          this.tableName = tableName;
      }
  
      public String getDescription() {
          return description;
      }
  
      public void setDescription(String description) {
          if (description == null)
              description = "";
          this.description = description;
      }
  }
  </code></pre>
  
  <p>The log is with root set to DEBUG.</p>
  
  <p>Does anyone have any idea what could be going on here, or any pointers in the direction of finding out ?</p>
  
  <p>Profiling perhaps ?
  The DBMS is mysql, just out of the box ubuntu.</p>