Mar 23 13:02:35 drbd2: PingAck did not arrive in time.
Mar 23 13:02:35 drbd2: short read expecting header on sock: r=-512
Mar 23 13:02:35 drbd2: tl_clear()
Mar 23 13:02:35 ben kernel: drbd2: PingAck did not arrive in time.
Mar 23 13:02:35 ben kernel: drbd2: peer( Primary -> Unknown ) conn( Connected -> NetworkFailure ) pdsk( UpToDate -> DUnknown ) 
Mar 23 13:02:35 ben kernel: drbd2: asender terminated
Mar 23 13:02:35 ben kernel: drbd2: short read expecting header on sock: r=-512
Mar 23 13:02:35 ben kernel: drbd2: tl_clear()
Mar 23 13:02:35 ben kernel: drbd2: Connection closed
Mar 23 13:02:35 ben kernel: drbd2: Writing meta data super block now.
Mar 23 13:02:35 ben kernel: drbd2: conn( NetworkFailure -> Unconnected ) 
Mar 23 13:02:35 ben kernel: drbd2: receiver terminated
Mar 23 13:02:35 ben kernel: drbd2: receiver (re)started
Mar 23 13:02:35 ben kernel: drbd2: conn( Unconnected -> WFConnection ) 
Mar 23 13:03:54 ben kernel: drbd2: role( Secondary -> Primary ) 
Mar 23 13:03:54 ben kernel: drbd2: Creating new current UUID
Mar 23 13:03:54 ben kernel: drbd2:  uuid[Bitmap] now 8A0F3A9F9E1A77C6
Mar 23 13:03:54 ben kernel: drbd2:  uuid[Current] now 6B0B1DA5CB20689D
Mar 23 13:03:54 ben kernel: drbd2: Writing meta data super block now.
Mar 23 13:05:18 ben kernel: drbd2: aftr_isp( 0 -> 1 ) 
Mar 23 13:05:19 ben kernel: drbd2: conn( WFConnection -> WFReportParams ) 
Mar 23 13:05:19 ben kernel: drbd2: Handshake successful: DRBD Network Protocol version 86
Mar 23 13:05:19 ben kernel: drbd2: drbd_sync_handshake:
Mar 23 13:05:19 ben kernel: drbd2: self 6B0B1DA5CB20689D:8A0F3A9F9E1A77C6:B450183638BDD68A:F6CE1616F9917C9F
Mar 23 13:05:19 ben kernel: drbd2: peer 8A0F3A9F9E1A77C7:0000000000000000:B450183638BDD68A:F6CE1616F9917C9F
Mar 23 13:05:19 ben kernel: drbd2: uuid_compare()=1 by rule 7
Mar 23 13:05:19 ben kernel: drbd2: peer( Unknown -> Secondary ) conn( WFReportParams -> WFBitMapS ) pdsk( DUnknown -> UpToDate ) peer_isp( 0 -> 1 ) 
Mar 23 13:05:19 ben kernel: drbd2: Writing meta data super block now.
Mar 23 13:05:22 ben kernel: drbd2:  uuid[History_start] now 8A0F3A9F9E1A77C6
Mar 23 13:05:22 ben kernel: drbd2:  uuid[Bitmap] now CB02C14FA3081C52
Mar 23 13:05:23 ben kernel: drbd2: conn( WFBitMapS -> PausedSyncS ) pdsk( UpToDate -> Inconsistent ) 
Mar 23 13:05:23 ben kernel: drbd2: Began resync as PausedSyncS (will sync 659464 KB [164866 bits set]).
Mar 23 13:05:23 ben kernel: drbd2: Writing meta data super block now.
Mar 23 13:06:21 ben kernel: drbd2: peer_isp( 1 -> 0 ) 
Mar 23 13:06:21 ben kernel: drbd2: conn( PausedSyncS -> SyncSource ) aftr_isp( 1 -> 0 ) 
Mar 23 13:06:21 ben kernel: drbd2: Syncer continues.
Mar 23 13:06:46 ben kernel: drbd2: Resync done (total 88 sec; paused 63 sec; 26376 K/sec)
Mar 23 13:06:46 ben kernel: drbd2:  uuid[History_start] now CB02C14FA3081C52
Mar 23 13:06:46 ben kernel: drbd2:  uuid[Bitmap] now 0000000000000000
Mar 23 13:06:46 ben kernel: drbd2: conn( SyncSource -> Connected ) pdsk( Inconsistent -> UpToDate ) 
Mar 23 13:06:46 ben kernel: drbd2: Writing meta data super block now.
<<<<<<<<<<<<<<<<<<<<POWER cycled here and rebooting ben>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
Mar 23 13:10:57 ben kernel: drbd2: disk( Diskless -> Attaching ) 
Mar 23 13:10:57 ben kernel: drbd2: Found 6 transactions (324 active extents) in activity log.
Mar 23 13:10:57 ben kernel: drbd2: max_segment_size ( = BIO size ) = 32768
Mar 23 13:10:57 ben kernel: drbd2: drbd_bm_resize called with capacity == 26672264
Mar 23 13:10:57 ben kernel: drbd2: resync bitmap: bits=3334033 words=104190
Mar 23 13:10:57 ben kernel: drbd2: size = 12 GB (13336132 KB)
Mar 23 13:10:57 ben kernel: drbd2: reading of bitmap took 2 jiffies
Mar 23 13:10:57 ben kernel: drbd2: recounting of set bits took additional 0 jiffies
Mar 23 13:10:57 ben kernel: drbd2: 0 KB marked out-of-sync by on disk bit-map.
Mar 23 13:10:58 ben kernel: drbd2: Marked additional 1028 MB as out-of-sync based on AL.
Mar 23 13:10:58 ben kernel: drbd2: disk( Attaching -> UpToDate ) 
Mar 23 13:10:58 ben kernel: drbd2: Writing meta data super block now.
Mar 23 13:11:01 ben kernel: drbd2: aftr_isp( 0 -> 1 ) 
Mar 23 13:11:01 ben kernel: drbd2: conn( StandAlone -> Unconnected ) 
Mar 23 13:11:02 ben kernel: drbd2: receiver (re)started
Mar 23 13:11:05 ben.sn.stratus.com login: Mar 23 13:11:02 ben kernel: drbd2: conn( Unconnected -> WFConnection ) 
Mar 23 13:11:02 ben kernel: drbd2: conn( WFConnection -> WFReportParams ) 
Mar 23 13:11:03 ben kernel: drbd2: Handshake successful: DRBD Network Protocol version 86
Mar 23 13:11:04 ben kernel: drbd2: drbd_sync_handshake:
Mar 23 13:11:04 ben kernel: drbd2: self 6B0B1DA5CB20689D:0000000000000000:CB02C14FA3081C52:8A0F3A9F9E1A77C6
Mar 23 13:11:04 ben kernel: drbd2: peer F71E503A8179BC5D:6B0B1DA5CB20689C:CB02C14FA3081C52:8A0F3A9F9E1A77C6
Mar 23 13:11:05 ben kernel: drbd2: uuid_compare()=-1 by rule 5
Mar 23 13:11:06 ben kernel: drbd2:  uuid[History_start] now 6B0B1DA5CB20689D
Mar 23 13:11:08 ben kernel: drbd2:  uuid[Current] now 6B0B1DA5CB20689C
Mar 23 13:11:09 ben kernel: drbd2: peer( Unknown -> Primary ) conn( WFReportParams -> WFBitMapT ) pdsk( DUnknown -> UpToDate ) peer_isp( 0 -> 1 ) 
Mar 23 13:11:10 ben kernel: drbd2: Writing meta data super block now.
Mar 23 13:11:18 ben kernel: drbd2: conn( WFBitMapT -> WFSyncUUID ) 
Mar 23 13:11:18 ben kernel: drbd2:  uuid[Current] now 3F430D4E1D59C3EA
Mar 23 13:11:18 ben kernel: drbd2:  uuid[Bitmap] now 0000000000000000
Mar 23 13:11:18 ben kernel: drbd2: conn( WFSyncUUID -> PausedSyncT ) disk( UpToDate -> Inconsistent ) 
Mar 23 13:11:18 ben kernel: drbd2: Began resync as PausedSyncT (will sync 1052696 KB [263174 bits set]).
Mar 23 13:11:18 ben kernel: drbd2: Writing meta data super block now.
Mar 23 13:12:09 ben kernel: drbd2: peer_isp( 1 -> 0 ) 
Mar 23 13:12:09 ben kernel: drbd2: conn( PausedSyncT -> SyncTarget ) aftr_isp( 1 -> 0 ) 
Mar 23 13:12:09 ben kernel: drbd2: Syncer continues.
Mar 23 13:12:46 ben kernel: drbd2: Resync done (total 111 sec; paused 74 sec; 28448 K/sec)
Mar 23 13:12:46 ben kernel: drbd2:  uuid[Bitmap] now 6B0B1DA5CB20689C
Mar 23 13:12:46 ben kernel: drbd2:  uuid[History_start] now CB02C14FA3081C52
Mar 23 13:12:46 ben kernel: drbd2:  uuid[History_end] now 8A0F3A9F9E1A77C6
Mar 23 13:12:46 ben kernel: drbd2:  uuid[History_start] now 6B0B1DA5CB20689C
Mar 23 13:12:46 ben kernel: drbd2:  uuid[Bitmap] now 3F430D4E1D59C3EA
Mar 23 13:12:46 ben kernel: drbd2:  uuid[Current] now F71E503A8179BC5C
Mar 23 13:12:46 ben kernel: drbd2:  uuid[History_start] now 3F430D4E1D59C3EA
Mar 23 13:12:46 ben kernel: drbd2:  uuid[Bitmap] now 0000000000000000
Mar 23 13:12:46 ben kernel: drbd2: conn( SyncTarget -> Connected ) disk( Inconsistent -> UpToDate ) 
Mar 23 13:12:46 ben kernel: drbd2: Writing meta data super block now.
Mar 23 13:14:09 drbd2: PingAck did not arrive in time.
Mar 23 13:14:09 drbd2: short read expecting header on sock: r=-512
Mar 23 13:14:09 ben kernel: drbd2: PingAck did not arrive in time.
Mar 23 13:14:09 drbd2: tl_clear()
Mar 23 13:14:09 ben kernel: drbd2: peer( Primary -> Unknown ) conn( Connected -> NetworkFailure ) pdsk( UpToDate -> DUnknown ) 
Mar 23 13:14:09 ben kernel: drbd2: asender terminated
Mar 23 13:14:09 ben kernel: drbd2: short read expecting header on sock: r=-512
Mar 23 13:14:09 ben kernel: drbd2: tl_clear()
Mar 23 13:14:09 ben kernel: drbd2: Connection closed
Mar 23 13:14:09 ben kernel: drbd2: Writing meta data super block now.
Mar 23 13:14:09 ben kernel: drbd2: conn( NetworkFailure -> Unconnected ) 
Mar 23 13:14:09 ben kernel: drbd2: receiver terminated
Mar 23 13:14:09 ben kernel: drbd2: receiver (re)started
Mar 23 13:14:09 ben kernel: drbd2: conn( Unconnected -> WFConnection ) 
Mar 23 13:16:46 drbd2: rct = 2 in /test_logs/builds/SuperNova/trunk/070323/platform/drbd/src/drbd/drbd_receiver.c:1878
<<<<<<<<<Log weirdness here we should have seen drbd_sync_hanshake messages..>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>>
Mar 23 13:16:47 ben kernel: drbd2: conn( WFConnection -> WFReportParams ) 
Mar 23 13:16:48 ben kernel: drbd2: aftr_isp( 0 -> 1 ) 
Mar 23 13:16:48 ben kernel: drbd2: Handshake successful: DRBD Network Protocol version 86
Mar 23 13:16:48 ben kernel: drbd2: peer( Unknown -> Secondary ) conn( WFReportParams -> Connected ) pdsk( DUnknown -> UpToDate ) peer_isp( 0 -> 1 ) 
Mar 23 13:16:48 ben kernel: drbd2: Writing meta data super block now.
Mar 23 13:16:49 ben kernel: drbd2: rct = 2 in /test_logs/builds/SuperNova/trunk/070323/platform/drbd/src/drbd/drbd_receiver.c:1878
Mar 23 13:16:49 ben kernel: drbd2: drbd_sync_handshake:
Mar 23 13:16:49 ben kernel: drbd2: self F71E503A8179BC5C:0000000000000000:3F430D4E1D59C3EA:6B0B1DA5CB20689C
Mar 23 13:16:49 ben kernel: drbd2: peer F71E503A8179BC5D:0000000000000000:3F430D4E1D59C3EA:6B0B1DA5CB20689C
Mar 23 13:16:49 ben kernel: drbd2: uuid_compare()=-1 by rule 4
Mar 23 13:16:49 ben kernel: drbd2:  uuid[History_start] now F71E503A8179BC5C
Mar 23 13:16:49 ben kernel: drbd2:  uuid[Current] now 0000000000000000
Mar 23 13:16:49 ben kernel: drbd2: conn( Connected -> WFBitMapT )  <<<<<<The problem>>>>> 
Mar 23 13:16:49 ben kernel: drbd2: Writing meta data super block now.
Mar 23 13:17:42 ben kernel: drbd2: peer_isp( 1 -> 0 ) 
Mar 23 13:17:42 ben kernel: drbd2: aftr_isp( 1 -> 0 )