(63784) 13/10/29 14:00:31 - INFO:    [47] SendCallToStore: start 
(63784) 13/10/29 14:00:31 - INFO:    Free Index 47 complete
(61764) 13/10/29 14:00:31 - INFO:    DisplayStatusMsg(Storeserver conenction established,Verbindung zum StoreServer hergestellt,Busy)
(61764) 13/10/29 14:00:31 - INFO:    DisplayStatusMsg(Send to Storeserver succeeded,Senden an StoreServer erfolgreich,Busy)
(61764) 13/10/29 14:00:31 - INFO:    SendToStoreserver: command executed on StoreServer 'tcp/49875/127.0.0.1'
(61764) 13/10/29 14:00:31 - INFO:    DisplayStatusMsg(Command executed on Storeserver ,Anweisung wurde auf Storeserver ausgeführt,Busy)
(63572) 13/10/29 14:00:31 - INFO:    foam from 127.0.0.1:59788
(
    STRING MasterKey tapicti0 37 ;
    STRING Command registerevent ;
    STRING MessageType fstoreserver ;
    LONG PartnerPort 49368 ;
    STRING ClientAddress tcp/51510/192.168.1.25 ;
    STRING ClientCallingPartyNumber 37 ;
    STRING ClientTapiLine 37 ;
    STRING PartnerIp 127.0.0.1 ;
    STRUCT EventReason 
    (
        STRING Key 92f6 2013_10_29_14_0_31 01727489264 0 1024 call ;
        STRING MasterKey tapicti0 37 ;
        STRING Command write ;
        STRING MessageType storageserver ;
        STRUCT Data 
        (
            ULONG ID 37622 ;
            STRING CalledPartyNumber  ;
            STRING CallingPartyNumber 01727489264 ;
            LONG Status 4132 ;
            LONG IsOutgoing 0 ;
            LONGLONG StartTime 1383051631 ;
            LONGLONG ConnectedTime 0 ;
            LONGLONG EndTime 1383051631 ;
            LONG Time 1383051631 ;
            ULONG Duration 0 ;
            SHORT Year 2013 ;
            SHORT Month 10 ;
            SHORT Day 29 ;
            SHORT Hour 14 ;
            SHORT Minute 0 ;
            SHORT Second 31 ;
            BOOL Dst 0 ;
        ) ;
    ) ;
    LONGLONG RcvJobTime 1383051631 ;
)

(63572) 13/10/29 14:00:31 - INFO:    GetUserByTapiLine: found 00B6CED4:37
(61764) 13/10/29 14:00:31 - INFO:    DisplayStatusMsg((null),(null),Busy)
(63572) 13/10/29 14:00:31 - INFO:    DoFoamJobsStoreserver(): sent '(
    STRING MessageType fstoreserver ;
    STRING Command CallChangedNotification ;
    LONG Status 200 ;
    STRING DisplayStatus Storage:!`stored!`calls!`change!`notification ;
)
' to user '00B6CED4' 'tcp/51510/192.168.1.25'.
(62676) 13/10/29 14:00:32 - INFO:    foam from 192.168.1.25:61846
(
    STRING MessageType storageserver ;
    STRING Command GetCalls ;
    STRING CallingPartyNumber 37 ;
    STRING PrimaryLine 37 ;
    STRING FoamPort 51510 ;
    LONGLONG RcvJobTime 1383051632 ;
)

(62676) 13/10/29 14:00:32 - INFO:    send Status: 30 'please wait for further info, i'm doing my best to put you in my userlist'
(62676) 13/10/29 14:00:32 - INFO:    DisplayStatusMsg(Using 15 of 2048 licensed Cti users,Verwende 15 von 2048 lizensierten CTI-Benutzer,Busy)
(62676) 13/10/29 14:00:32 - INFO:    UpdateUserList(): users license allocated (needed:15 vs. available:2048).
(62676) 13/10/29 14:00:32 - INFO:    TAPI phone '37' is in service for user '00B6CED4', LineCount='1', LineNames='37'
(62676) 13/10/29 14:00:32 - INFO:    send Status: 16 '37'
(62676) 13/10/29 14:00:32 - INFO:    TAPI line '37' is in service for user '00B6CED4'
(62676) 13/10/29 14:00:32 - INFO:    send Status: 16 '37'
(62676) 13/10/29 14:00:32 - INFO:    UpdateUserList: 00B6CED4:37:37
(62676) 13/10/29 14:00:32 - INFO:    DisplayStatusMsg(Storeserver conenction established,Verbindung zum StoreServer hergestellt,Busy)
(62676) 13/10/29 14:00:32 - INFO:    DisplayStatusMsg(Send to Storeserver succeeded,Senden an StoreServer erfolgreich,Busy)
(64140) 13/10/29 14:00:32 - INFO:    DisplayStatusMsg(Storeserver conenction established,Verbindung zum StoreServer hergestellt,Busy)
(64140) 13/10/29 14:00:32 - INFO:    DisplayStatusMsg(Send to Storeserver succeeded,Senden an StoreServer erfolgreich,Busy)
(64140) 13/10/29 14:00:32 - INFO:    SendToStoreserver: command executed on StoreServer 'tcp/49875/127.0.0.1'
(64140) 13/10/29 14:00:32 - INFO:    DisplayStatusMsg(Command executed on Storeserver ,Anweisung wurde auf Storeserver ausgeführt,Busy)
(64140) 13/10/29 14:00:32 - INFO:    DisplayStatusMsg((null),(null),Busy)
(62676) 13/10/29 14:00:33 - INFO:    SendToStoreserver: command executed on StoreServer 'tcp/49875/127.0.0.1'
(62676) 13/10/29 14:00:33 - INFO:    DisplayStatusMsg(Command executed on Storeserver ,Anweisung wurde auf Storeserver ausgeführt,Busy)
(62676) 13/10/29 14:00:33 - INFO:    DisplayStatusMsg((null),(null),Busy)
(4724) 13/10/29 14:00:41 - INFO:    FindIndex: search for CallHandle=128cf idxstart=0
(4724) 13/10/29 14:00:41 - INFO:    GetUserByTapiLine: found 00B6CE8C:68
(4724) 13/10/29 14:00:41 - INFO:    DisplayStatusMsg(Using 2 of 2 licensed tapilines,Verwende 2 von 2 lizensierten Tapi-Lines,Busy)
(4724) 13/10/29 14:00:41 - INFO:    AllocNewIndex(): new lines license allocated (needed:2 (allocated:2) vs. available:2).
(4724) 13/10/29 14:00:41 - INFO:    FindIndex: search for CallHandle=128cf idxstart=0
(4724) 13/10/29 14:00:41 - INFO:    [48] LINECALLSTATE_DIALTONE
(4724) 13/10/29 14:00:41 - INFO:    [phnumcor] MakePhoneNumExt(): raw address '' after automatic correction: ''.
(4724) 13/10/29 14:00:41 - INFO:    DisplayChannel(48,,,out,492944,103)
(4724) 13/10/29 14:00:41 - INFO:    [48] ECTStateChange to TR2_DIALTONE
(4724) 13/10/29 14:00:41 - INFO:    FindIndex: search for CallHandle=128cf idxstart=0
(63596) 13/10/29 14:00:41 - INFO:    [48] connect to user '00B6CE8C' 'tcp/49232/192.168.1.153' FoamServer=00B748E0 OK because ''
(4724) 13/10/29 14:00:41 - INFO:    FindIndex: search for CallHandle=128cf idxstart=0
(63680) 13/10/29 14:00:41 - INFO:    [48] FoamThread: start
(4724) 13/10/29 14:00:41 - INFO:    FindIndex: search for CallHandle=128cf idxstart=0
(4724) 13/10/29 14:00:41 - INFO:    [48] LINECALLSTATE_PROCEEDING
(4724) 13/10/29 14:00:41 - INFO:    [phnumcor] MakePhoneNumExt(): raw address '' after automatic correction: ''.
(4724) 13/10/29 14:00:41 - INFO:    DisplayChannel(48,,,out,492944,109)
(4724) 13/10/29 14:00:41 - INFO:    [48] ECTStateChange to TR2_PROCEEDING
(4724) 13/10/29 14:00:41 - INFO:    FindIndex: search for CallHandle=128cf idxstart=0
(4724) 13/10/29 14:00:41 - INFO:    FindIndex: search for CallHandle=128cf idxstart=0
(4724) 13/10/29 14:00:41 - INFO:    [phnumcor] MakePhoneNumExt(): raw address '38' after automatic correction: '38'.
(4724) 13/10/29 14:00:41 - INFO:    DisplayChannel(48,,38,out,492944,109)
(4724) 13/10/29 14:00:41 - WARNING: [48] ECTStateChange: double status send
(4724) 13/10/29 14:00:41 - INFO:    [48] ECTStateChange to TR2_PROCEEDING
(4724) 13/10/29 14:00:41 - INFO:    FindIndex: search for CallHandle=12bb0 idxstart=0
(4724) 13/10/29 14:00:41 - WARNING: GetUserByTapiLine: 38:38 not found
(4724) 13/10/29 14:00:41 - INFO:    FindIndex: search for CallHandle=12bb0 idxstart=0
(4724) 13/10/29 14:00:41 - INFO:    [49] LINECALLSTATE_OFFERING
(4724) 13/10/29 14:00:41 - INFO:    [phnumcor] MakePhoneNumExt(): automatic phone number correction not available for '38'.
(4724) 13/10/29 14:00:41 - INFO:    DisplayChannel(49,68,38,in,0,101)
(4724) 13/10/29 14:00:41 - INFO:    [49] ECTStateChange to TR2_OFFERING
(4724) 13/10/29 14:00:41 - INFO:    FindIndex: search for CallHandle=12bb0 idxstart=0
(4724) 13/10/29 14:00:41 - INFO:    FindIndex: search for CallHandle=12bb0 idxstart=0
(4724) 13/10/29 14:00:41 - INFO:    [phnumcor] MakePhoneNumExt(): automatic phone number correction not available for '38'.
(4724) 13/10/29 14:00:41 - INFO:    DisplayChannel(49,68,38,in,0,101)
(4724) 13/10/29 14:00:42 - WARNING: [49] ECTStateChange: double status send
(4724) 13/10/29 14:00:42 - INFO:    [49] ECTStateChange to TR2_OFFERING
(4724) 13/10/29 14:00:42 - INFO:    FindIndex: search for CallHandle=12bb0 idxstart=0
(4724) 13/10/29 14:00:42 - INFO:    FindIndex: search for CallHandle=12bb0 idxstart=0
(4724) 13/10/29 14:00:42 - INFO:    FindIndex: search for CallHandle=12bb0 idxstart=0
(4724) 13/10/29 14:00:42 - INFO:    FindIndex: search for CallHandle=128cf idxstart=0
(4724) 13/10/29 14:00:42 - INFO:    [48] LINECALLSTATE_RINGBACK
(4724) 13/10/29 14:00:42 - INFO:    [phnumcor] MakePhoneNumExt(): raw address '38' after automatic correction: '38'.
(4724) 13/10/29 14:00:42 - INFO:    DisplayChannel(48,68,38,out,492944,105)
(4724) 13/10/29 14:00:42 - INFO:    [48] ECTStateChange to TR2_RINGBACK
(4724) 13/10/29 14:00:42 - INFO:    FindIndex: search for CallHandle=128cf idxstart=0
(4724) 13/10/29 14:00:42 - INFO:    FindIndex: search for CallHandle=128cf idxstart=0
(4724) 13/10/29 14:00:42 - INFO:    [phnumcor] MakePhoneNumExt(): raw address '38' after automatic correction: '38'.
(4724) 13/10/29 14:00:42 - INFO:    DisplayChannel(48,68,38,out,492944,105)
(4724) 13/10/29 14:00:42 - WARNING: [48] ECTStateChange: double status send
(4724) 13/10/29 14:00:42 - INFO:    [48] ECTStateChange to TR2_RINGBACK
(4724) 13/10/29 14:00:50 - INFO:    FindIndex: search for CallHandle=128cf idxstart=0
(4724) 13/10/29 14:00:50 - INFO:    [48] LINECALLSTATE_IDLE
(4724) 13/10/29 14:00:50 - INFO:    [phnumcor] MakePhoneNumExt(): raw address '38' after automatic correction: '38'.
(4724) 13/10/29 14:00:50 - INFO:    DisplayChannel(48,,,out,492944,100)
(4724) 13/10/29 14:00:50 - INFO:    [48] ECTStateChange to TR2_IDLE
(4724) 13/10/29 14:00:50 - INFO:    FindIndex: search for CallHandle=12bb0 idxstart=0
(4724) 13/10/29 14:00:50 - INFO:    [49] LINECALLSTATE_IDLE
(4724) 13/10/29 14:00:50 - INFO:    [phnumcor] MakePhoneNumExt(): automatic phone number correction not available for '38'.
(4724) 13/10/29 14:00:50 - INFO:    DisplayChannel(49,,,in,0,100)
(4724) 13/10/29 14:00:50 - INFO:    [49] ECTStateChange to TR2_IDLE
(4724) 13/10/29 14:00:50 - INFO:    Freeing Index 49 
(4724) 13/10/29 14:00:50 - INFO:    FindIndex: search for CallHandle=12bb0 idxstart=0
(4724) 13/10/29 14:00:50 - INFO:    FindIndex: search for CallHandle=12bb0 idxstart=50
(4724) 13/10/29 14:00:50 - INFO:    [49] SendCallToStore: start 
(4724) 13/10/29 14:00:50 - INFO:    Free Index 49 complete
(56288) 13/10/29 14:00:50 - INFO:    DisplayStatusMsg(Storeserver conenction established,Verbindung zum StoreServer hergestellt,Busy)
(56288) 13/10/29 14:00:50 - INFO:    DisplayStatusMsg(Send to Storeserver succeeded,Senden an StoreServer erfolgreich,Busy)
(56288) 13/10/29 14:00:50 - INFO:    SendToStoreserver: command executed on StoreServer 'tcp/49875/127.0.0.1'
(56288) 13/10/29 14:00:50 - INFO:    DisplayStatusMsg(Command executed on Storeserver ,Anweisung wurde auf Storeserver ausgeführt,Busy)
(56288) 13/10/29 14:00:50 - INFO:    DisplayStatusMsg((null),(null),Busy)
(63596) 13/10/29 14:00:50 - INFO:    Freeing Index 48 
(63596) 13/10/29 14:00:50 - INFO:    DisplayStatusMsg(Using 1 of 2 licensed tapilines,Verwende 1 von 2 lizensierten Tapi-Lines,Busy)
(63596) 13/10/29 14:00:50 - INFO:    FreeIndex(48): lines license freed (needed:1 vs. available:2).
(63680) 13/10/29 14:00:50 - INFO:    [48] FoamThread: foam closed
(63596) 13/10/29 14:00:50 - INFO:    FindIndex: search for CallHandle=128cf idxstart=0
(63596) 13/10/29 14:00:50 - INFO:    FindIndex: search for CallHandle=128cf idxstart=49
(63596) 13/10/29 14:00:50 - INFO:    [48] SendCallToStore: start 
(63596) 13/10/29 14:00:50 - INFO:    Free Index 48 complete
(63772) 13/10/29 14:00:50 - INFO:    DisplayStatusMsg(Storeserver conenction established,Verbindung zum StoreServer hergestellt,Busy)
(63772) 13/10/29 14:00:50 - INFO:    DisplayStatusMsg(Send to Storeserver succeeded,Senden an StoreServer erfolgreich,Busy)
(63772) 13/10/29 14:00:50 - INFO:    SendToStoreserver: command executed on StoreServer 'tcp/49875/127.0.0.1'
(63772) 13/10/29 14:00:50 - INFO:    DisplayStatusMsg(Command executed on Storeserver ,Anweisung wurde auf Storeserver ausgeführt,Busy)
(56868) 13/10/29 14:00:50 - INFO:    foam from 127.0.0.1:59811
(
    STRING MasterKey tapicti0 68 ;
    STRING Command registerevent ;
    STRING MessageType fstoreserver ;
    LONG PartnerPort 49368 ;
    STRING ClientAddress tcp/49232/192.168.1.153 ;
    STRING ClientCallingPartyNumber 68 ;
    STRING ClientTapiLine 68 ;
    STRING PartnerIp 127.0.0.1 ;
    STRUCT EventReason 
    (
        STRING Key 92f7 2013_10_29_14_0_50 38 0 28 call ;
        STRING MasterKey tapicti0 68 ;
        STRING Command write ;
        STRING MessageType storageserver ;
        STRUCT Data 
        (
            ULONG ID 37623 ;
            STRING CalledPartyNumber 38 ;
            STRING CallingPartyNumber  ;
            LONG Status 40 ;
            LONG IsOutgoing 1 ;
            LONGLONG StartTime 1383051641 ;
            LONGLONG ConnectedTime 0 ;
            LONGLONG EndTime 1383051650 ;
            LONG Time 1383051650 ;
            ULONG Duration 0 ;
            SHORT Year 2013 ;
            SHORT Month 10 ;
            SHORT Day 29 ;
            SHORT Hour 14 ;
            SHORT Minute 0 ;
            SHORT Second 50 ;
            BOOL Dst 0 ;
        ) ;
    ) ;
    LONGLONG RcvJobTime 1383051650 ;
)

(56868) 13/10/29 14:00:50 - INFO:    GetUserByTapiLine: found 00B6CE8C:68
(63772) 13/10/29 14:00:50 - INFO:    DisplayStatusMsg((null),(null),Busy)
(56868) 13/10/29 14:00:50 - INFO:    DoFoamJobsStoreserver(): sent '(
    STRING MessageType fstoreserver ;
    STRING Command CallChangedNotification ;
    LONG Status 200 ;
    STRING DisplayStatus Storage:!`stored!`calls!`change!`notification ;
)
' to user '00B6CE8C' 'tcp/49232/192.168.1.153'.
(62292) 13/10/29 14:00:50 - INFO:    foam from 192.168.1.153:51505
(
    STRING MessageType storageserver ;
    STRING Command GetCalls ;
    STRING CallingPartyNumber 68 ;
    STRING PrimaryLine 68 ;
    STRING FoamPort 49232 ;
    LONGLONG RcvJobTime 1383051650 ;
)

(62292) 13/10/29 14:00:50 - INFO:    send Status: 30 'please wait for further info, i'm doing my best to put you in my userlist'
(62292) 13/10/29 14:00:50 - INFO:    DisplayStatusMsg(Using 15 of 2048 licensed Cti users,Verwende 15 von 2048 lizensierten CTI-Benutzer,Busy)
(62292) 13/10/29 14:00:50 - INFO:    UpdateUserList(): users license allocated (needed:15 vs. available:2048).
(62292) 13/10/29 14:00:50 - INFO:    TAPI phone '68' is in service for user '00B6CE8C', LineCount='1', LineNames='68'
(62292) 13/10/29 14:00:50 - INFO:    send Status: 16 '68'
(62292) 13/10/29 14:00:50 - INFO:    TAPI line '68' is in service for user '00B6CE8C'
(62292) 13/10/29 14:00:50 - INFO:    send Status: 16 '68'
(62292) 13/10/29 14:00:50 - INFO:    UpdateUserList: 00B6CE8C:68:68
(62292) 13/10/29 14:00:50 - INFO:    DisplayStatusMsg(Storeserver conenction established,Verbindung zum StoreServer hergestellt,Busy)
(62292) 13/10/29 14:00:51 - INFO:    DisplayStatusMsg(Send to Storeserver succeeded,Senden an StoreServer erfolgreich,Busy)
(61136) 13/10/29 14:00:51 - INFO:    DisplayStatusMsg(Storeserver conenction established,Verbindung zum StoreServer hergestellt,Busy)
(61136) 13/10/29 14:00:51 - INFO:    DisplayStatusMsg(Send to Storeserver succeeded,Senden an StoreServer erfolgreich,Busy)
(61136) 13/10/29 14:00:51 - INFO:    SendToStoreserver: command executed on StoreServer 'tcp/49875/127.0.0.1'
(61136) 13/10/29 14:00:51 - INFO:    DisplayStatusMsg(Command executed on Storeserver ,Anweisung wurde auf Storeserver ausgeführt,Busy)
(61136) 13/10/29 14:00:51 - INFO:    DisplayStatusMsg((null),(null),Busy)
(4724) 13/10/29 14:00:53 - INFO:    FindIndex: search for CallHandle=12b4c idxstart=0
(4724) 13/10/29 14:00:53 - INFO:    [46] LINECALLSTATE_IDLE
(4724) 13/10/29 14:00:53 - INFO:    [phnumcor] MakePhoneNumExt(): automatic phone number correction not available for '37'.
(4724) 13/10/29 14:00:53 - INFO:    DisplayChannel(46,,,in,492942,100)
(4724) 13/10/29 14:00:53 - INFO:    [46] ECTStateChange to TR2_IDLE
(64208) 13/10/29 14:00:53 - INFO:    Freeing Index 46 
(64208) 13/10/29 14:00:53 - INFO:    DisplayStatusMsg(Using 0 of 2 licensed tapilines,Verwende 0 von 2 lizensierten Tapi-Lines,Busy)
(64208) 13/10/29 14:00:53 - INFO:    FreeIndex(46): lines license freed (needed:0 vs. available:2).
(62644) 13/10/29 14:00:53 - INFO:    [46] FoamThread: foam closed
(64208) 13/10/29 14:00:53 - INFO:    FindIndex: search for CallHandle=12b4c idxstart=0
(64208) 13/10/29 14:00:53 - INFO:    FindIndex: search for CallHandle=12b4c idxstart=47
(64208) 13/10/29 14:00:53 - INFO:    [46] SendCallToStore: start 
(64208) 13/10/29 14:00:53 - INFO:    Free Index 46 complete
(63912) 13/10/29 14:00:53 - INFO:    DisplayStatusMsg(Storeserver conenction established,Verbindung zum StoreServer hergestellt,Busy)
(63912) 13/10/29 14:00:53 - INFO:    DisplayStatusMsg(Send to Storeserver succeeded,Senden an StoreServer erfolgreich,Busy)
(63912) 13/10/29 14:00:53 - INFO:    SendToStoreserver: command executed on StoreServer 'tcp/49875/127.0.0.1'
(63912) 13/10/29 14:00:53 - INFO:    DisplayStatusMsg(Command executed on Storeserver ,Anweisung wurde auf Storeserver ausgeführt,Busy)
(63912) 13/10/29 14:00:53 - INFO:    DisplayStatusMsg((null),(null),Busy)
(63972) 13/10/29 14:00:53 - INFO:    foam from 127.0.0.1:59818
(
    STRING MasterKey tapicti0 37 ;
    STRING Command registerevent ;
    STRING MessageType fstoreserver ;
    LONG PartnerPort 49368 ;
    STRING ClientAddress tcp/51510/192.168.1.25 ;
    STRING ClientCallingPartyNumber 37 ;
    STRING ClientTapiLine 37 ;
    STRING PartnerIp 127.0.0.1 ;
    STRUCT EventReason 
    (
        STRING Key 92f4 2013_10_29_14_0_53 01727447551 0 1024 call ;
        STRING MasterKey tapicti0 37 ;
        STRING Command write ;
        STRING MessageType storageserver ;
        STRUCT Data 
        (
            ULONG ID 37620 ;
            STRING CalledPartyNumber  ;
            STRING CallingPartyNumber 01727447551 ;
            LONG Status 4132 ;
            LONG IsOutgoing 0 ;
            LONGLONG StartTime 1383051623 ;
            LONGLONG ConnectedTime 0 ;
            LONGLONG EndTime 1383051653 ;
            LONG Time 1383051653 ;
            ULONG Duration 0 ;
            SHORT Year 2013 ;
            SHORT Month 10 ;
            SHORT Day 29 ;
            SHORT Hour 14 ;
            SHORT Minute 0 ;
            SHORT Second 53 ;
            BOOL Dst 0 ;
        ) ;
    ) ;
    LONGLONG RcvJobTime 1383051653 ;
)

(63972) 13/10/29 14:00:53 - INFO:    GetUserByTapiLine: found 00B6CED4:37
(63972) 13/10/29 14:00:53 - INFO:    DoFoamJobsStoreserver(): sent '(
    STRING MessageType fstoreserver ;
    STRING Command CallChangedNotification ;
    LONG Status 200 ;
    STRING DisplayStatus Storage:!`stored!`calls!`change!`notification ;
)
' to user '00B6CED4' 'tcp/51510/192.168.1.25'.
(63668) 13/10/29 14:00:54 - INFO:    foam from 192.168.1.25:61858
(
    STRING MessageType storageserver ;
    STRING Command GetCalls ;
    STRING CallingPartyNumber 37 ;
    STRING PrimaryLine 37 ;
    STRING FoamPort 51510 ;
    LONGLONG RcvJobTime 1383051654 ;
)

(63668) 13/10/29 14:00:54 - INFO:    send Status: 30 'please wait for further info, i'm doing my best to put you in my userlist'
(63668) 13/10/29 14:00:54 - INFO:    DisplayStatusMsg(Using 15 of 2048 licensed Cti users,Verwende 15 von 2048 lizensierten CTI-Benutzer,Busy)
(63668) 13/10/29 14:00:54 - INFO:    UpdateUserList(): users license allocated (needed:15 vs. available:2048).
(63668) 13/10/29 14:00:54 - INFO:    TAPI phone '37' is in service for user '00B6CED4', LineCount='1', LineNames='37'
(63668) 13/10/29 14:00:54 - INFO:    send Status: 16 '37'
(63668) 13/10/29 14:00:54 - INFO:    TAPI line '37' is in service for user '00B6CED4'
(63668) 13/10/29 14:00:54 - INFO:    send Status: 16 '37'
(63668) 13/10/29 14:00:54 - INFO:    UpdateUserList: 00B6CED4:37:37
(63668) 13/10/29 14:00:54 - INFO:    DisplayStatusMsg(Storeserver conenction established,Verbindung zum StoreServer hergestellt,Busy)
(63668) 13/10/29 14:00:54 - INFO:    DisplayStatusMsg(Send to Storeserver succeeded,Senden an StoreServer erfolgreich,Busy)
(64068) 13/10/29 14:00:54 - INFO:    DisplayStatusMsg(Storeserver conenction established,Verbindung zum StoreServer hergestellt,Busy)
(64068) 13/10/29 14:00:54 - INFO:    DisplayStatusMsg(Send to Storeserver succeeded,Senden an StoreServer erfolgreich,Busy)
(62292) 13/10/29 14:00:54 - INFO:    SendToStoreserver: command executed on StoreServer 'tcp/49875/127.0.0.1'
(62292) 13/10/29 14:00:54 - INFO:    DisplayStatusMsg(Command executed on Storeserver ,Anweisung wurde auf Storeserver ausgeführt,Busy)
(62292) 13/10/29 14:00:54 - INFO:    DisplayStatusMsg((null),(null),Busy)
(64068) 13/10/29 14:00:54 - INFO:    SendToStoreserver: command executed on StoreServer 'tcp/49875/127.0.0.1'
(64068) 13/10/29 14:00:54 - INFO:    DisplayStatusMsg(Command executed on Storeserver ,Anweisung wurde auf Storeserver ausgeführt,Busy)
(64068) 13/10/29 14:00:54 - INFO:    DisplayStatusMsg((null),(null),Busy)
(63668) 13/10/29 14:00:56 - INFO:    SendToStoreserver: command executed on StoreServer 'tcp/49875/127.0.0.1'
(63668) 13/10/29 14:00:56 - INFO:    DisplayStatusMsg(Command executed on Storeserver ,Anweisung wurde auf Storeserver ausgeführt,Busy)
(63668) 13/10/29 14:00:56 - INFO:    DisplayStatusMsg((null),(null),Busy)
(4724) 13/10/29 14:00:57 - INFO:    FindIndex: search for CallHandle=130ad idxstart=0
(4724) 13/10/29 14:00:57 - WARNING: GetUserByTapiLine: :38 not found
(4724) 13/10/29 14:00:57 - INFO:    FindIndex: search for CallHandle=130ad idxstart=0
(4724) 13/10/29 14:00:57 - INFO:    [50] LINECALLSTATE_DIALTONE
(4724) 13/10/29 14:00:57 - INFO:    [phnumcor] MakePhoneNumExt(): raw address '' after automatic correction: ''.
(4724) 13/10/29 14:00:57 - INFO:    DisplayChannel(50,,,out,0,103)
(4724) 13/10/29 14:00:57 - INFO:    [50] ECTStateChange to TR2_DIALTONE
(4724) 13/10/29 14:00:57 - INFO:    FindIndex: search for CallHandle=130ad idxstart=0
(4724) 13/10/29 14:00:57 - INFO:    FindIndex: search for CallHandle=130ad idxstart=0
(4696) 13/10/29 14:00:57 - INFO:    DisplayStatusMsg(Using 15 of 2048 licensed Cti users,Verwende 15 von 2048 lizensierten CTI-Benutzer,Busy)
(4696) 13/10/29 14:00:57 - INFO:    TimerThread(): user license allocated (needed:15 vs. available:2048).
(4724) 13/10/29 14:00:57 - INFO:    FindIndex: search for CallHandle=130ad idxstart=0
(4724) 13/10/29 14:00:57 - INFO:    [50] LINECALLSTATE_PROCEEDING
(4724) 13/10/29 14:00:57 - INFO:    [phnumcor] MakePhoneNumExt(): raw address '' after automatic correction: ''.
(4724) 13/10/29 14:00:57 - INFO:    DisplayChannel(50,,,out,0,109)
(4724) 13/10/29 14:00:57 - INFO:    [50] ECTStateChange to TR2_PROCEEDING
(4724) 13/10/29 14:00:57 - INFO:    FindIndex: search for CallHandle=130ad idxstart=0
(4724) 13/10/29 14:00:57 - INFO:    FindIndex: search for CallHandle=130ad idxstart=0
(4724) 13/10/29 14:00:57 - INFO:    [phnumcor] MakePhoneNumExt(): raw address '68' after automatic correction: '68'.
(4724) 13/10/29 14:00:57 - INFO:    DisplayChannel(50,,68,out,0,109)
(4724) 13/10/29 14:00:57 - WARNING: [50] ECTStateChange: double status send
(4724) 13/10/29 14:00:57 - INFO:    [50] ECTStateChange to TR2_PROCEEDING
(4724) 13/10/29 14:00:58 - INFO:    FindIndex: search for CallHandle=13369 idxstart=0
(4724) 13/10/29 14:00:58 - INFO:    GetUserByTapiLine: found 00B6CE8C:68
(4724) 13/10/29 14:00:58 - INFO:    DisplayStatusMsg(Using 1 of 2 licensed tapilines,Verwende 1 von 2 lizensierten Tapi-Lines,Busy)
(4724) 13/10/29 14:00:58 - INFO:    AllocNewIndex(): new lines license allocated (needed:1 (allocated:1) vs. available:2).
(4724) 13/10/29 14:00:58 - INFO:    FindIndex: search for CallHandle=13369 idxstart=0
(4724) 13/10/29 14:00:58 - INFO:    [51] LINECALLSTATE_OFFERING
(4724) 13/10/29 14:00:58 - INFO:    [phnumcor] MakePhoneNumExt(): automatic phone number correction not available for '68'.
(4724) 13/10/29 14:00:58 - INFO:    DisplayChannel(51,38,68,in,492945,101)
(4724) 13/10/29 14:00:58 - INFO:    [51] ECTStateChange to TR2_OFFERING
(4724) 13/10/29 14:00:58 - INFO:    FindIndex: search for CallHandle=13369 idxstart=0
(60664) 13/10/29 14:00:58 - INFO:    [51] connect to user '00B6CE8C' 'tcp/49232/192.168.1.153' FoamServer=00B74698 OK because ''
(4724) 13/10/29 14:00:58 - INFO:    FindIndex: search for CallHandle=13369 idxstart=0
(4724) 13/10/29 14:00:58 - INFO:    [phnumcor] MakePhoneNumExt(): automatic phone number correction not available for '68'.
(4724) 13/10/29 14:00:58 - INFO:    DisplayChannel(51,38,68,in,492945,101)
(4724) 13/10/29 14:00:58 - WARNING: [51] ECTStateChange: double status send
(4724) 13/10/29 14:00:58 - INFO:    [51] ECTStateChange to TR2_OFFERING
(62392) 13/10/29 14:00:58 - INFO:    [51] FoamThread: start
(4724) 13/10/29 14:00:58 - INFO:    FindIndex: search for CallHandle=13369 idxstart=0
(4724) 13/10/29 14:00:58 - INFO:    FindIndex: search for CallHandle=13369 idxstart=0
(4724) 13/10/29 14:00:58 - INFO:    FindIndex: search for CallHandle=13369 idxstart=0
(4724) 13/10/29 14:00:58 - INFO:    FindIndex: search for CallHandle=130ad idxstart=0
(4724) 13/10/29 14:00:58 - INFO:    [50] LINECALLSTATE_RINGBACK
(4724) 13/10/29 14:00:58 - INFO:    [phnumcor] MakePhoneNumExt(): raw address '68' after automatic correction: '68'.
(4724) 13/10/29 14:00:58 - INFO:    DisplayChannel(50,38,68,out,0,105)
(4724) 13/10/29 14:00:58 - INFO:    [50] ECTStateChange to TR2_RINGBACK
(4724) 13/10/29 14:00:58 - INFO:    FindIndex: search for CallHandle=130ad idxstart=0
(4724) 13/10/29 14:00:58 - INFO:    FindIndex: search for CallHandle=130ad idxstart=0
(4724) 13/10/29 14:00:58 - INFO:    [phnumcor] MakePhoneNumExt(): raw address '68' after automatic correction: '68'.
(4724) 13/10/29 14:00:58 - INFO:    DisplayChannel(50,38,68,out,0,105)
(4724) 13/10/29 14:00:58 - WARNING: [50] ECTStateChange: double status send
(4724) 13/10/29 14:00:58 - INFO:    [50] ECTStateChange to TR2_RINGBACK
(4724) 13/10/29 14:01:00 - INFO:    FindIndex: search for CallHandle=13369 idxstart=0
(4724) 13/10/29 14:01:00 - INFO:    [51] LINECALLSTATE_CONNECTED
(4724) 13/10/29 14:01:00 - INFO:    [phnumcor] MakePhoneNumExt(): automatic phone number correction not available for '68'.
(4724) 13/10/29 14:01:00 - INFO:    DisplayChannel(51,38,68,in,492945,108)
(4724) 13/10/29 14:01:00 - INFO:    [51] ECTStateChange to TR2_CONNECTED
(4724) 13/10/29 14:01:00 - INFO:    FindIndex: search for CallHandle=13369 idxstart=0
(4724) 13/10/29 14:01:00 - INFO:    [phnumcor] MakePhoneNumExt(): automatic phone number correction not available for '68'.
(4724) 13/10/29 14:01:00 - INFO:    DisplayChannel(51,38,68,in,492945,108)
(4724) 13/10/29 14:01:00 - WARNING: [51] ECTStateChange: double status send
(4724) 13/10/29 14:01:00 - INFO:    [51] ECTStateChange to TR2_CONNECTED
(4724) 13/10/29 14:01:00 - INFO:    FindIndex: search for CallHandle=13369 idxstart=0
(4724) 13/10/29 14:01:00 - INFO:    FindIndex: search for CallHandle=13369 idxstart=0
(4724) 13/10/29 14:01:00 - INFO:    [phnumcor] MakePhoneNumExt(): automatic phone number correction not available for '68'.
(4724) 13/10/29 14:01:00 - INFO:    DisplayChannel(51,38,68,in,492945,108)
(4724) 13/10/29 14:01:00 - WARNING: [51] ECTStateChange: double status send
(4724) 13/10/29 14:01:00 - INFO:    [51] ECTStateChange to TR2_CONNECTED
(4724) 13/10/29 14:01:00 - INFO:    FindIndex: search for CallHandle=130ad idxstart=0
(4724) 13/10/29 14:01:00 - INFO:    [50] LINECALLSTATE_CONNECTED
(4724) 13/10/29 14:01:00 - INFO:    [phnumcor] MakePhoneNumExt(): raw address '68' after automatic correction: '68'.
(4724) 13/10/29 14:01:00 - INFO:    DisplayChannel(50,38,68,out,0,108)
(4724) 13/10/29 14:01:00 - INFO:    [50] ECTStateChange to TR2_CONNECTED
(4724) 13/10/29 14:01:00 - INFO:    FindIndex: search for CallHandle=130ad idxstart=0
(4724) 13/10/29 14:01:00 - INFO:    FindIndex: search for CallHandle=130ad idxstart=0
(4724) 13/10/29 14:01:00 - INFO:    [phnumcor] MakePhoneNumExt(): raw address '68' after automatic correction: '68'.
(4724) 13/10/29 14:01:00 - INFO:    DisplayChannel(50,38,68,out,0,108)
(4724) 13/10/29 14:01:00 - WARNING: [50] ECTStateChange: double status send
(4724) 13/10/29 14:01:00 - INFO:    [50] ECTStateChange to TR2_CONNECTED
(4724) 13/10/29 14:01:00 - INFO:    FindIndex: search for CallHandle=130ad idxstart=0
(4724) 13/10/29 14:01:00 - INFO:    [phnumcor] MakePhoneNumExt(): raw address '68' after automatic correction: '68'.
(4724) 13/10/29 14:01:00 - INFO:    DisplayChannel(50,38,68,out,0,108)
(4724) 13/10/29 14:01:00 - WARNING: [50] ECTStateChange: double status send
(4724) 13/10/29 14:01:00 - INFO:    [50] ECTStateChange to TR2_CONNECTED
(4724) 13/10/29 14:01:12 - INFO:    FindIndex: search for CallHandle=1319f idxstart=0
(4724) 13/10/29 14:01:12 - INFO:    [38] LINECALLSTATE_IDLE
(4724) 13/10/29 14:01:12 - INFO:    [phnumcor] MakePhoneNumExt(): automatic phone number correction not available for '93'.
(4724) 13/10/29 14:01:12 - INFO:    DisplayChannel(38,,,in,0,100)
(4724) 13/10/29 14:01:12 - INFO:    [38] ECTStateChange to TR2_IDLE
(4724) 13/10/29 14:01:12 - INFO:    Freeing Index 38 
(4724) 13/10/29 14:01:12 - INFO:    FindIndex: search for CallHandle=1319f idxstart=0
(4724) 13/10/29 14:01:12 - INFO:    FindIndex: search for CallHandle=1319f idxstart=39
(4724) 13/10/29 14:01:12 - INFO:    [38] SendCallToStore: start 
(4724) 13/10/29 14:01:12 - INFO:    Free Index 38 complete
(63960) 13/10/29 14:01:12 - INFO:    DisplayStatusMsg(Storeserver conenction established,Verbindung zum StoreServer hergestellt,Busy)
(63960) 13/10/29 14:01:12 - INFO:    DisplayStatusMsg(Send to Storeserver succeeded,Senden an StoreServer erfolgreich,Busy)
(63960) 13/10/29 14:01:12 - INFO:    SendToStoreserver: command executed on StoreServer 'tcp/49875/127.0.0.1'
(63960) 13/10/29 14:01:12 - INFO:    DisplayStatusMsg(Command executed on Storeserver ,Anweisung wurde auf Storeserver ausgeführt,Busy)
(63960) 13/10/29 14:01:12 - INFO:    DisplayStatusMsg((null),(null),Busy)
(64128) 13/10/29 14:01:16 - INFO:    foam from 192.168.1.33:53304
(
    STRING MessageType fndialclient ;
    STRING Heartbeat Heartbeat ;
    STRING CalledPartyNumber foo_dummy ;
    STRING FoamPort 50242 ;
    STRING CallingPartyNumber 29 ;
    STRING PrimaryLine 29 ;
    LONGLONG RcvJobTime 1383051676 ;
)

(64128) 13/10/29 14:01:16 - INFO:    foam Phone[0]:'foo_dummy'
(64128) 13/10/29 14:01:16 - INFO:    foam Caller[0]:'29'
(64128) 13/10/29 14:01:16 - INFO:    heart is beating 0:
(64128) 13/10/29 14:01:16 - INFO:    send Status: 30 'please wait for further info, i'm doing my best to put you in my userlist'
(64128) 13/10/29 14:01:16 - INFO:    DisplayStatusMsg(Using 15 of 2048 licensed Cti users,Verwende 15 von 2048 lizensierten CTI-Benutzer,Busy)
(64128) 13/10/29 14:01:16 - INFO:    UpdateUserList(): users license allocated (needed:15 vs. available:2048).
(64128) 13/10/29 14:01:16 - WARNING: 29 (10) LinesInServiceCount: Line '29' out of service
(64128) 13/10/29 14:01:16 - WARNING: 29 LinesInServiceCount: no lines in service
(64128) 13/10/29 14:01:16 - WARNING: 29 (10) GetTapiLine: Line '29' not in service 
(64128) 13/10/29 14:01:16 - ERROR:   29 IsLineInService: GetTapiLine '(null)' failed 
(64128) 13/10/29 14:01:16 - ERROR:   TAPI phone '29' is unknown for user '00B6CEC8'
(64128) 13/10/29 14:01:16 - WARNING: 29 (10) GetTapiLine: Line '29' not in service 
(64128) 13/10/29 14:01:16 - ERROR:   (null) IsLineInService: GetTapiLine '29' failed 
(64128) 13/10/29 14:01:16 - ERROR:   TAPI line '29' is unknown for user '00B6CEC8'
(64128) 13/10/29 14:01:16 - INFO:    send Status: 30 'please wait for further info, i'm doing my best to put you in my userlist'
(64128) 13/10/29 14:01:16 - INFO:    DisplayStatusMsg(Using 15 of 2048 licensed Cti users,Verwende 15 von 2048 lizensierten CTI-Benutzer,Busy)
(64128) 13/10/29 14:01:16 - INFO:    UpdateUserList(): users license allocated (needed:15 vs. available:2048).
(64128) 13/10/29 14:01:16 - WARNING: 29 (10) LinesInServiceCount: Line '29' out of service
(64128) 13/10/29 14:01:16 - WARNING: 29 LinesInServiceCount: no lines in service
(64128) 13/10/29 14:01:16 - WARNING: 29 (10) GetTapiLine: Line '29' not in service 
(64128) 13/10/29 14:01:16 - ERROR:   29 IsLineInService: GetTapiLine '(null)' failed 
(64128) 13/10/29 14:01:16 - ERROR:   TAPI phone '29' is unknown for user '00B6CEC8'
(64128) 13/10/29 14:01:16 - WARNING: 29 (10) GetTapiLine: Line '29' not in service 
(64128) 13/10/29 14:01:16 - ERROR:   (null) IsLineInService: GetTapiLine '29' failed 
(64128) 13/10/29 14:01:16 - ERROR:   TAPI line '29' is unknown for user '00B6CEC8'
(64128) 13/10/29 14:01:16 - INFO:    send Status: 12 'Unbekannte Leitung'
(4724) 13/10/29 14:01:24 - INFO:    FindIndex: search for CallHandle=116d0 idxstart=0
(4724) 13/10/29 14:01:24 - WARNING: GetUserByTapiLine: 771:771 not found
(4724) 13/10/29 14:01:24 - INFO:    FindIndex: search for CallHandle=116d0 idxstart=0
(4724) 13/10/29 14:01:24 - INFO:    [52] LINECALLSTATE_OFFERING
(4724) 13/10/29 14:01:24 - INFO:    [phnumcor] MakePhoneNumExt(): automatic phone number correction not available for '771'.
(4724) 13/10/29 14:01:24 - INFO:    DisplayChannel(52,06102788321,771,in,0,101)
(4724) 13/10/29 14:01:24 - INFO:    [52] ECTStateChange to TR2_OFFERING
(4724) 13/10/29 14:01:24 - INFO:    FindIndex: search for CallHandle=116d0 idxstart=0
(4724) 13/10/29 14:01:24 - INFO:    FindIndex: search for CallHandle=116d0 idxstart=0
(4724) 13/10/29 14:01:24 - INFO:    [phnumcor] MakePhoneNumExt(): automatic phone number correction not available for '771'.
(4724) 13/10/29 14:01:24 - INFO:    DisplayChannel(52,06102788321,771,in,0,101)
(4724) 13/10/29 14:01:24 - WARNING: [52] ECTStateChange: double status send
(4724) 13/10/29 14:01:24 - INFO:    [52] ECTStateChange to TR2_OFFERING
(4724) 13/10/29 14:01:24 - INFO:    FindIndex: search for CallHandle=116d0 idxstart=0
(4724) 13/10/29 14:01:24 - INFO:    FindIndex: search for CallHandle=116d0 idxstart=0
(4724) 13/10/29 14:01:24 - INFO:    FindIndex: search for CallHandle=116d0 idxstart=0
(4724) 13/10/29 14:01:24 - INFO:    FindIndex: search for CallHandle=116d0 idxstart=0
(4724) 13/10/29 14:01:30 - INFO:    FindIndex: search for CallHandle=116d0 idxstart=0
(4724) 13/10/29 14:01:30 - INFO:    [52] LINECALLSTATE_CONNECTED
(4724) 13/10/29 14:01:30 - INFO:    [phnumcor] MakePhoneNumExt(): automatic phone number correction not available for '771'.
(4724) 13/10/29 14:01:30 - INFO:    DisplayChannel(52,06102788321,771,in,0,108)
(4724) 13/10/29 14:01:30 - INFO:    [52] ECTStateChange to TR2_CONNECTED
(4724) 13/10/29 14:01:30 - INFO:    FindIndex: search for CallHandle=116d0 idxstart=0
(4724) 13/10/29 14:01:30 - INFO:    [phnumcor] MakePhoneNumExt(): automatic phone number correction not available for '771'.
(4724) 13/10/29 14:01:30 - INFO:    DisplayChannel(52,06102788321,771,in,0,108)
(4724) 13/10/29 14:01:30 - WARNING: [52] ECTStateChange: double status send
(4724) 13/10/29 14:01:30 - INFO:    [52] ECTStateChange to TR2_CONNECTED
(4724) 13/10/29 14:01:30 - INFO:    FindIndex: search for CallHandle=116d0 idxstart=0
(4724) 13/10/29 14:01:30 - INFO:    FindIndex: search for CallHandle=116d0 idxstart=0
(4724) 13/10/29 14:01:30 - INFO:    [phnumcor] MakePhoneNumExt(): automatic phone number correction not available for '771'.
(4724) 13/10/29 14:01:30 - INFO:    DisplayChannel(52,06102788321,771,in,0,108)
(4724) 13/10/29 14:01:30 - WARNING: [52] ECTStateChange: double status send
(4724) 13/10/29 14:01:30 - INFO:    [52] ECTStateChange to TR2_CONNECTED
(4724) 13/10/29 14:01:30 - INFO:    FindIndex: search for CallHandle=116d0 idxstart=0
(4724) 13/10/29 14:01:30 - INFO:    FindIndex: search for CallHandle=116d0 idxstart=0
(4696) 13/10/29 14:01:31 - INFO:    DisplayStatusMsg(Using 1 of 2 licensed tapilines,Verwende 1 von 2 lizensierten Tapi-Lines,Busy)
(4696) 13/10/29 14:01:31 - INFO:    TimerThread(): lines license allocated (needed:1 vs. available:2).
(64060) 13/10/29 14:01:35 - INFO:    foam from 192.168.1.14:52539
(
    STRING MessageType fndialclient ;
    STRING Heartbeat Heartbeat ;
    STRING CalledPartyNumber foo_dummy ;
    STRING FoamPort 49414 ;
    STRING CallingPartyNumber 742 ;
    STRING PrimaryLine 742 ;
    LONGLONG RcvJobTime 1383051695 ;
)

(64060) 13/10/29 14:01:35 - INFO:    foam Phone[0]:'foo_dummy'
(64060) 13/10/29 14:01:35 - INFO:    foam Caller[0]:'742'
(64060) 13/10/29 14:01:35 - INFO:    heart is beating 0:
(64060) 13/10/29 14:01:35 - INFO:    send Status: 30 'please wait for further info, i'm doing my best to put you in my userlist'
(64060) 13/10/29 14:01:35 - INFO:    DisplayStatusMsg(Using 15 of 2048 licensed Cti users,Verwende 15 von 2048 lizensierten CTI-Benutzer,Busy)
(64060) 13/10/29 14:01:35 - INFO:    UpdateUserList(): users license allocated (needed:15 vs. available:2048).
(64060) 13/10/29 14:01:35 - WARNING: 742 LinesInServiceCount: no lines in service
(64060) 13/10/29 14:01:35 - ERROR:   742 IsLineInService: GetTapiLine '(null)' failed 
(64060) 13/10/29 14:01:35 - ERROR:   TAPI phone '742' is unknown for user '00B6CEB0'
(64060) 13/10/29 14:01:35 - ERROR:   (null) IsLineInService: GetTapiLine '742' failed 
(64060) 13/10/29 14:01:35 - ERROR:   TAPI line '742' is unknown for user '00B6CEB0'
(64060) 13/10/29 14:01:35 - INFO:    send Status: 30 'please wait for further info, i'm doing my best to put you in my userlist'
(64060) 13/10/29 14:01:35 - INFO:    DisplayStatusMsg(Using 15 of 2048 licensed Cti users,Verwende 15 von 2048 lizensierten CTI-Benutzer,Busy)
(64060) 13/10/29 14:01:35 - INFO:    UpdateUserList(): users license allocated (needed:15 vs. available:2048).
(64060) 13/10/29 14:01:35 - WARNING: 742 LinesInServiceCount: no lines in service
(64060) 13/10/29 14:01:35 - ERROR:   742 IsLineInService: GetTapiLine '(null)' failed 
(64060) 13/10/29 14:01:35 - ERROR:   TAPI phone '742' is unknown for user '00B6CEB0'
(64060) 13/10/29 14:01:35 - ERROR:   (null) IsLineInService: GetTapiLine '742' failed 
(64060) 13/10/29 14:01:35 - ERROR:   TAPI line '742' is unknown for user '00B6CEB0'
(64060) 13/10/29 14:01:35 - INFO:    send Status: 12 'Unbekannte Leitung'
(4724) 13/10/29 14:01:35 - INFO:    FindIndex: search for CallHandle=130ad idxstart=0
(4724) 13/10/29 14:01:35 - INFO:    [50] LINECALLSTATE_IDLE
(4724) 13/10/29 14:01:35 - INFO:    [phnumcor] MakePhoneNumExt(): raw address '68' after automatic correction: '68'.
(4724) 13/10/29 14:01:35 - INFO:    DisplayChannel(50,,,out,0,100)
(4724) 13/10/29 14:01:35 - INFO:    [50] ECTStateChange to TR2_IDLE
(4724) 13/10/29 14:01:35 - INFO:    Freeing Index 50 
(4724) 13/10/29 14:01:35 - INFO:    FindIndex: search for CallHandle=130ad idxstart=0
(4724) 13/10/29 14:01:35 - INFO:    FindIndex: search for CallHandle=130ad idxstart=51
(4724) 13/10/29 14:01:35 - INFO:    [50] SendCallToStore: start 
(4724) 13/10/29 14:01:35 - INFO:    Free Index 50 complete
(64008) 13/10/29 14:01:35 - INFO:    DisplayStatusMsg(Storeserver conenction established,Verbindung zum StoreServer hergestellt,Busy)
(4724) 13/10/29 14:01:35 - INFO:    FindIndex: search for CallHandle=13369 idxstart=0
(4724) 13/10/29 14:01:35 - INFO:    [51] LINECALLSTATE_DISCONNECTED
(4724) 13/10/29 14:01:35 - INFO:    [phnumcor] MakePhoneNumExt(): automatic phone number correction not available for '68'.
(4724) 13/10/29 14:01:35 - INFO:    DisplayChannel(51,,,in,492945,114)
(4724) 13/10/29 14:01:35 - INFO:    [51] ECTStateChange to TR2_DISCONNECTED
(64008) 13/10/29 14:01:35 - INFO:    DisplayStatusMsg(Send to Storeserver succeeded,Senden an StoreServer erfolgreich,Busy)
(64008) 13/10/29 14:01:35 - INFO:    SendToStoreserver: command executed on StoreServer 'tcp/49875/127.0.0.1'
(64008) 13/10/29 14:01:35 - INFO:    DisplayStatusMsg(Command executed on Storeserver ,Anweisung wurde auf Storeserver ausgeführt,Busy)
(64008) 13/10/29 14:01:35 - INFO:    DisplayStatusMsg((null),(null),Busy)
(4724) 13/10/29 14:01:36 - INFO:    FindIndex: search for CallHandle=13369 idxstart=0
(4724) 13/10/29 14:01:36 - INFO:    [51] LINECALLSTATE_IDLE
(4724) 13/10/29 14:01:36 - INFO:    [phnumcor] MakePhoneNumExt(): automatic phone number correction not available for '68'.
(4724) 13/10/29 14:01:36 - INFO:    DisplayChannel(51,,,in,492945,100)
(4724) 13/10/29 14:01:36 - INFO:    [51] ECTStateChange to TR2_IDLE
(60664) 13/10/29 14:01:36 - INFO:    Freeing Index 51 
(60664) 13/10/29 14:01:36 - INFO:    DisplayStatusMsg(Using 0 of 2 licensed tapilines,Verwende 0 von 2 lizensierten Tapi-Lines,Busy)
(60664) 13/10/29 14:01:36 - INFO:    FreeIndex(51): lines license freed (needed:0 vs. available:2).
(62392) 13/10/29 14:01:36 - INFO:    [51] FoamThread: foam closed
(60664) 13/10/29 14:01:36 - INFO:    FindIndex: search for CallHandle=13369 idxstart=0
(60664) 13/10/29 14:01:36 - INFO:    FindIndex: search for CallHandle=13369 idxstart=52
(60664) 13/10/29 14:01:36 - INFO:    [51] SendCallToStore: start 
(60664) 13/10/29 14:01:36 - INFO:    Free Index 51 complete
(63320) 13/10/29 14:01:36 - INFO:    DisplayStatusMsg(Storeserver conenction established,Verbindung zum StoreServer hergestellt,Busy)
(63320) 13/10/29 14:01:36 - INFO:    DisplayStatusMsg(Send to Storeserver succeeded,Senden an StoreServer erfolgreich,Busy)
(63320) 13/10/29 14:01:36 - INFO:    SendToStoreserver: command executed on StoreServer 'tcp/49875/127.0.0.1'
(63320) 13/10/29 14:01:36 - INFO:    DisplayStatusMsg(Command executed on Storeserver ,Anweisung wurde auf Storeserver ausgeführt,Busy)
(64228) 13/10/29 14:01:36 - INFO:    foam from 127.0.0.1:59857
(
    STRING MasterKey tapicti0 68 ;
    STRING Command registerevent ;
    STRING MessageType fstoreserver ;
    LONG PartnerPort 49368 ;
    STRING ClientAddress tcp/49232/192.168.1.153 ;
    STRING ClientCallingPartyNumber 68 ;
    STRING ClientTapiLine 68 ;
    STRING PartnerIp 127.0.0.1 ;
    STRUCT EventReason 
    (
        STRING Key 92f8 2013_10_29_14_1_36 38 35 2124 call ;
        STRING MasterKey tapicti0 68 ;
        STRING Command write ;
        STRING MessageType storageserver ;
        STRUCT Data 
        (
            ULONG ID 37624 ;
            STRING CalledPartyNumber  ;
            STRING CallingPartyNumber 38 ;
            LONG Status 8484 ;
            LONG IsOutgoing 0 ;
            LONGLONG StartTime 1383051658 ;
            LONGLONG ConnectedTime 1383051660 ;
            LONGLONG EndTime 1383051695 ;
            LONG Time 1383051696 ;
            ULONG Duration 35 ;
            SHORT Year 2013 ;
            SHORT Month 10 ;
            SHORT Day 29 ;
            SHORT Hour 14 ;
            SHORT Minute 1 ;
            SHORT Second 36 ;
            BOOL Dst 0 ;
        ) ;
    ) ;
    LONGLONG RcvJobTime 1383051696 ;
)

(64228) 13/10/29 14:01:36 - INFO:    GetUserByTapiLine: found 00B6CE8C:68
(63320) 13/10/29 14:01:36 - INFO:    DisplayStatusMsg((null),(null),Busy)
(64228) 13/10/29 14:01:36 - INFO:    DoFoamJobsStoreserver(): sent '(
    STRING MessageType fstoreserver ;
    STRING Command CallChangedNotification ;
    LONG Status 200 ;
    STRING DisplayStatus Storage:!`stored!`calls!`change!`notification ;
)
' to user '00B6CE8C' 'tcp/49232/192.168.1.153'.
(55264) 13/10/29 14:01:37 - INFO:    foam from 192.168.1.153:51524
(
    STRING MessageType storageserver ;
    STRING Command GetCalls ;
    STRING CallingPartyNumber 68 ;
    STRING PrimaryLine 68 ;
    STRING FoamPort 49232 ;
    LONGLONG RcvJobTime 1383051697 ;
)

(55264) 13/10/29 14:01:37 - INFO:    send Status: 30 'please wait for further info, i'm doing my best to put you in my userlist'
(55264) 13/10/29 14:01:37 - INFO:    DisplayStatusMsg(Using 15 of 2048 licensed Cti users,Verwende 15 von 2048 lizensierten CTI-Benutzer,Busy)
(55264) 13/10/29 14:01:37 - INFO:    UpdateUserList(): users license allocated (needed:15 vs. available:2048).
(55264) 13/10/29 14:01:37 - INFO:    TAPI phone '68' is in service for user '00B6CE8C', LineCount='1', LineNames='68'
(55264) 13/10/29 14:01:37 - INFO:    send Status: 16 '68'
(55264) 13/10/29 14:01:37 - INFO:    TAPI line '68' is in service for user '00B6CE8C'
(55264) 13/10/29 14:01:37 - INFO:    send Status: 16 '68'
(55264) 13/10/29 14:01:37 - INFO:    UpdateUserList: 00B6CE8C:68:68
(55264) 13/10/29 14:01:37 - INFO:    DisplayStatusMsg(Storeserver conenction established,Verbindung zum StoreServer hergestellt,Busy)
(55264) 13/10/29 14:01:37 - INFO:    DisplayStatusMsg(Send to Storeserver succeeded,Senden an StoreServer erfolgreich,Busy)
(64204) 13/10/29 14:01:37 - INFO:    DisplayStatusMsg(Storeserver conenction established,Verbindung zum StoreServer hergestellt,Busy)
(64204) 13/10/29 14:01:37 - INFO:    DisplayStatusMsg(Send to Storeserver succeeded,Senden an StoreServer erfolgreich,Busy)
(64204) 13/10/29 14:01:37 - INFO:    SendToStoreserver: command executed on StoreServer 'tcp/49875/127.0.0.1'
(64204) 13/10/29 14:01:37 - INFO:    DisplayStatusMsg(Command executed on Storeserver ,Anweisung wurde auf Storeserver ausgeführt,Busy)
(64204) 13/10/29 14:01:37 - INFO:    DisplayStatusMsg((null),(null),Busy)
(4724) 13/10/29 14:01:38 - INFO:    FindIndex: search for CallHandle=13299 idxstart=0
(4724) 13/10/29 14:01:38 - WARNING: GetUserByTapiLine: :38 not found
(4724) 13/10/29 14:01:38 - INFO:    FindIndex: search for CallHandle=13299 idxstart=0
(4724) 13/10/29 14:01:38 - INFO:    [53] LINECALLSTATE_DIALTONE
(4724) 13/10/29 14:01:38 - INFO:    [phnumcor] MakePhoneNumExt(): raw address '' after automatic correction: ''.
(4724) 13/10/29 14:01:38 - INFO:    DisplayChannel(53,,,out,0,103)
(4724) 13/10/29 14:01:38 - INFO:    [53] ECTStateChange to TR2_DIALTONE
(4724) 13/10/29 14:01:38 - INFO:    FindIndex: search for CallHandle=13299 idxstart=0
(4724) 13/10/29 14:01:38 - INFO:    FindIndex: search for CallHandle=13299 idxstart=0
(4724) 13/10/29 14:01:40 - INFO:    FindIndex: search for CallHandle=13299 idxstart=0
(4724) 13/10/29 14:01:40 - INFO:    [53] LINECALLSTATE_DIALING
(4724) 13/10/29 14:01:40 - INFO:    [phnumcor] MakePhoneNumExt(): raw address '' after automatic correction: ''.
(4724) 13/10/29 14:01:40 - INFO:    DisplayChannel(53,,,out,0,104)
(4724) 13/10/29 14:01:40 - INFO:    [53] ECTStateChange to TR2_DIALING
(4724) 13/10/29 14:01:40 - INFO:    FindIndex: search for CallHandle=13299 idxstart=0
(4724) 13/10/29 14:01:40 - INFO:    FindIndex: search for CallHandle=13299 idxstart=0
(55264) 13/10/29 14:01:40 - INFO:    SendToStoreserver: command executed on StoreServer 'tcp/49875/127.0.0.1'
(55264) 13/10/29 14:01:40 - INFO:    DisplayStatusMsg(Command executed on Storeserver ,Anweisung wurde auf Storeserver ausgeführt,Busy)
(55264) 13/10/29 14:01:40 - INFO:    DisplayStatusMsg((null),(null),Busy)
(4724) 13/10/29 14:01:46 - INFO:    FindIndex: search for CallHandle=13299 idxstart=0
(4724) 13/10/29 14:01:46 - INFO:    [53] LINECALLSTATE_PROCEEDING
(4724) 13/10/29 14:01:46 - INFO:    [phnumcor] MakePhoneNumExt(): raw address '' after automatic correction: ''.
(4724) 13/10/29 14:01:46 - INFO:    DisplayChannel(53,38,,out,0,109)
(4724) 13/10/29 14:01:46 - INFO:    [53] ECTStateChange to TR2_PROCEEDING
(4724) 13/10/29 14:01:46 - INFO:    FindIndex: search for CallHandle=13299 idxstart=0
(4724) 13/10/29 14:01:46 - INFO:    FindIndex: search for CallHandle=13299 idxstart=0
(4724) 13/10/29 14:01:46 - INFO:    [phnumcor] MakePhoneNumExt(): raw address '0041562456310' after automatic correction: '0041562456310'.
(4724) 13/10/29 14:01:46 - INFO:    DisplayChannel(53,38,0041562456310,out,0,109)
(4724) 13/10/29 14:01:46 - WARNING: [53] ECTStateChange: double status send
(4724) 13/10/29 14:01:46 - INFO:    [53] ECTStateChange to TR2_PROCEEDING
(4724) 13/10/29 14:01:46 - INFO:    FindIndex: search for CallHandle=13299 idxstart=0
(4724) 13/10/29 14:01:46 - INFO:    [53] LINECALLSTATE_RINGBACK
(4724) 13/10/29 14:01:46 - INFO:    [phnumcor] MakePhoneNumExt(): raw address '0041562456310' after automatic correction: '0041562456310'.
(4724) 13/10/29 14:01:46 - INFO:    DisplayChannel(53,38,0041562456310,out,0,105)
(4724) 13/10/29 14:01:46 - INFO:    [53] ECTStateChange to TR2_RINGBACK
(4724) 13/10/29 14:01:46 - INFO:    FindIndex: search for CallHandle=13299 idxstart=0
(4724) 13/10/29 14:01:46 - INFO:    FindIndex: search for CallHandle=13299 idxstart=0
(4724) 13/10/29 14:01:46 - INFO:    [phnumcor] MakePhoneNumExt(): raw address '0041562456310' after automatic correction: '0041562456310'.
(4724) 13/10/29 14:01:46 - INFO:    DisplayChannel(53,38,0041562456310,out,0,105)
(4724) 13/10/29 14:01:46 - WARNING: [53] ECTStateChange: double status send
(4724) 13/10/29 14:01:46 - INFO:    [53] ECTStateChange to TR2_RINGBACK
(4724) 13/10/29 14:01:46 - INFO:    FindIndex: search for CallHandle=13299 idxstart=0
(4724) 13/10/29 14:01:50 - INFO:    FindIndex: search for CallHandle=13299 idxstart=0
(4724) 13/10/29 14:01:50 - INFO:    [53] LINECALLSTATE_CONNECTED
(4724) 13/10/29 14:01:50 - INFO:    [phnumcor] MakePhoneNumExt(): raw address '0041562456310' after automatic correction: '0041562456310'.
(4724) 13/10/29 14:01:50 - INFO:    DisplayChannel(53,38,0041562456310,out,0,108)
(4724) 13/10/29 14:01:50 - INFO:    [53] ECTStateChange to TR2_CONNECTED
(4724) 13/10/29 14:01:50 - INFO:    FindIndex: search for CallHandle=13299 idxstart=0
(4724) 13/10/29 14:01:50 - INFO:    FindIndex: search for CallHandle=13299 idxstart=0
(4724) 13/10/29 14:01:50 - INFO:    [phnumcor] MakePhoneNumExt(): raw address '0041562456310' after automatic correction: '0041562456310'.
(4724) 13/10/29 14:01:50 - INFO:    DisplayChannel(53,38,0041562456310,out,0,108)
(4724) 13/10/29 14:01:50 - WARNING: [53] ECTStateChange: double status send
(4724) 13/10/29 14:01:50 - INFO:    [53] ECTStateChange to TR2_CONNECTED
(4724) 13/10/29 14:01:50 - INFO:    FindIndex: search for CallHandle=13299 idxstart=0
(4724) 13/10/29 14:01:50 - INFO:    [phnumcor] MakePhoneNumExt(): raw address '0041562456310' after automatic correction: '0041562456310'.
(4724) 13/10/29 14:01:50 - INFO:    DisplayChannel(53,38,0041562456310,out,0,108)
(4724) 13/10/29 14:01:50 - WARNING: [53] ECTStateChange: double status send
(4724) 13/10/29 14:01:50 - INFO:    [53] ECTStateChange to TR2_CONNECTED
(4724) 13/10/29 14:01:50 - INFO:    FindIndex: search for CallHandle=13299 idxstart=0
(4724) 13/10/29 14:01:50 - INFO:    FindIndex: search for CallHandle=13299 idxstart=0
(4724) 13/10/29 14:01:50 - INFO:    FindIndex: search for CallHandle=13299 idxstart=0
(61896) 13/10/29 14:01:53 - INFO:    foam from 192.168.1.148:3916
(
    STRING MessageType fndialclient ;
    STRING Heartbeat Heartbeat ;
    STRING CalledPartyNumber foo_dummy ;
    STRING FoamPort 4684 ;
    STRING CallingPartyNumber 44 ;
    STRING PrimaryLine 44 ;
    LONGLONG RcvJobTime 1383051713 ;
)

(61896) 13/10/29 14:01:53 - INFO:    foam Phone[0]:'foo_dummy'
(61896) 13/10/29 14:01:53 - INFO:    foam Caller[0]:'44'
(61896) 13/10/29 14:01:53 - INFO:    heart is beating 0:
(61896) 13/10/29 14:01:53 - INFO:    send Status: 30 'please wait for further info, i'm doing my best to put you in my userlist'
(61896) 13/10/29 14:01:53 - INFO:    DisplayStatusMsg(Using 15 of 2048 licensed Cti users,Verwende 15 von 2048 lizensierten CTI-Benutzer,Busy)
(61896) 13/10/29 14:01:53 - INFO:    UpdateUserList(): users license allocated (needed:15 vs. available:2048).
(61896) 13/10/29 14:01:53 - INFO:    TAPI phone '44' is in service for user '00B6CEBC', LineCount='1', LineNames='44'
(61896) 13/10/29 14:01:53 - INFO:    send Status: 16 '44'
(61896) 13/10/29 14:01:53 - INFO:    TAPI line '44' is in service for user '00B6CEBC'
(61896) 13/10/29 14:01:53 - INFO:    send Status: 16 '44'
(61896) 13/10/29 14:01:53 - INFO:    UpdateUserList: 00B6CEBC:44:44
(61896) 13/10/29 14:01:53 - INFO:    send Status: 42 '192.168.1.148'
(64200) 13/10/29 14:01:53 - INFO:    DisplayStatusMsg(Storeserver conenction established,Verbindung zum StoreServer hergestellt,Busy)
(64200) 13/10/29 14:01:53 - INFO:    DisplayStatusMsg(Send to Storeserver succeeded,Senden an StoreServer erfolgreich,Busy)
(64200) 13/10/29 14:01:53 - INFO:    SendToStoreserver: command executed on StoreServer 'tcp/49875/127.0.0.1'
(64200) 13/10/29 14:01:53 - INFO:    DisplayStatusMsg(Command executed on Storeserver ,Anweisung wurde auf Storeserver ausgeführt,Busy)
(64200) 13/10/29 14:01:53 - INFO:    DisplayStatusMsg((null),(null),Busy)